1 | #include "globals.h"
|
---|
2 | #include <syslog.h>
|
---|
3 | #include <stdlib.h>
|
---|
4 |
|
---|
5 | static FILE *fp=(FILE *)0;
|
---|
6 | static FILE *fps=(FILE *)0;
|
---|
7 | static int16_t logStarted = 0;
|
---|
8 |
|
---|
9 | pthread_mutex_t switching_log;
|
---|
10 | pthread_mutex_t loghistory_lock;
|
---|
11 |
|
---|
12 | #ifdef CS_ANTICASC
|
---|
13 | FILE *fpa=(FILE *)0;
|
---|
14 | #endif
|
---|
15 |
|
---|
16 | #define LOG_BUF_SIZE (520+11) // should be aligned with s_client.dump from globals.h
|
---|
17 |
|
---|
18 | static void switch_log(char* file, FILE **f, int32_t (*pfinit)(void))
|
---|
19 | {
|
---|
20 | if( cfg.max_log_size) //only 1 thread needs to switch the log; even if anticasc, statistics and normal log are running
|
---|
21 | //at the same time, it is ok to have the other logs switching 1 entry later
|
---|
22 | {
|
---|
23 | struct stat stlog;
|
---|
24 |
|
---|
25 | if( stat(file, &stlog)!=0 )
|
---|
26 | {
|
---|
27 | fprintf(stderr, "stat('%s',..) failed (errno=%d %s)\n", file, errno, strerror(errno));
|
---|
28 | return;
|
---|
29 | }
|
---|
30 |
|
---|
31 | if( stlog.st_size >= cfg.max_log_size*1024 && *f != NULL) {
|
---|
32 | int32_t rc;
|
---|
33 | char prev_log[strlen(file) + 6];
|
---|
34 | snprintf(prev_log, sizeof(prev_log), "%s-prev", file);
|
---|
35 | if ( cs_trylock(&switching_log) == 0) { //I got the lock so I am the first thread detecting a switchlog is needed
|
---|
36 | FILE *tmp = *f;
|
---|
37 | *f = (FILE *)0;
|
---|
38 | fprintf(tmp, "switch log file\n");
|
---|
39 | cs_sleepms(1);
|
---|
40 | fflush(tmp);
|
---|
41 | fclose(tmp);
|
---|
42 | rc = rename(file, prev_log);
|
---|
43 | if( rc!=0 ) {
|
---|
44 | fprintf(stderr, "rename(%s, %s) failed (errno=%d %s)\n", file, prev_log, errno, strerror(errno));
|
---|
45 | }
|
---|
46 | else
|
---|
47 | if( pfinit()){
|
---|
48 | fprintf(stderr, "Initialisation of log file failed, continuing without logging thread %8X. Log will be output to stdout!", (unsigned int)pthread_self());
|
---|
49 | cfg.logtostdout = 1;
|
---|
50 | }
|
---|
51 | }
|
---|
52 | else //I am not the first to detect a switchlog is needed, so I need to wait for the first thread to complete
|
---|
53 | cs_lock(&switching_log); //wait on 1st thread
|
---|
54 | cs_unlock(&switching_log); //release after processing or after waiting
|
---|
55 | }
|
---|
56 | }
|
---|
57 | }
|
---|
58 |
|
---|
59 | void cs_write_log(char *txt)
|
---|
60 | {
|
---|
61 | #ifdef CS_ANTICASC
|
---|
62 | struct s_client *cl = cur_client();
|
---|
63 | if( cl && cl->typ == 'a' && fpa ) {
|
---|
64 | switch_log(cfg.ac_logfile, &fpa, ac_init_log);
|
---|
65 | if (fpa) {
|
---|
66 | fputs(txt, fpa);
|
---|
67 | fflush(fpa);
|
---|
68 | }
|
---|
69 | }
|
---|
70 | else
|
---|
71 | #endif
|
---|
72 | // filter out entries with leading 's' and forward to statistics
|
---|
73 | if(txt[0] == 's') {
|
---|
74 | if (fps) {
|
---|
75 | switch_log(cfg.usrfile, &fps, cs_init_statistics);
|
---|
76 | if (fps) {
|
---|
77 | fputs(txt + 1, fps); // remove the leading 's' and write to file
|
---|
78 | fflush(fps);
|
---|
79 | }
|
---|
80 | }
|
---|
81 | } else {
|
---|
82 | if(!cfg.disablelog){
|
---|
83 | if (fp){
|
---|
84 | switch_log(cfg.logfile, &fp, cs_open_logfiles);
|
---|
85 | if (fp) {
|
---|
86 | fputs(txt, fp);
|
---|
87 | fflush(fp);
|
---|
88 | }
|
---|
89 | }
|
---|
90 | if(cfg.logtostdout){
|
---|
91 | fputs(txt, stdout);
|
---|
92 | fflush(stdout);
|
---|
93 | }
|
---|
94 | }
|
---|
95 | }
|
---|
96 | }
|
---|
97 |
|
---|
98 | int32_t cs_open_logfiles()
|
---|
99 | {
|
---|
100 | char *starttext;
|
---|
101 | if(logStarted) starttext = "log switched";
|
---|
102 | else starttext = "started";
|
---|
103 | if (!fp && cfg.logfile != NULL) { //log to file
|
---|
104 | if ((fp = fopen(cfg.logfile, "a+")) <= (FILE *)0) {
|
---|
105 | fp = (FILE *)0;
|
---|
106 | fprintf(stderr, "couldn't open logfile: %s (errno %d %s)\n", cfg.logfile, errno, strerror(errno));
|
---|
107 | } else {
|
---|
108 | time_t t;
|
---|
109 | char line[80];
|
---|
110 | memset(line, '-', sizeof(line));
|
---|
111 | line[(sizeof(line)/sizeof(char)) - 1] = '\0';
|
---|
112 | time(&t);
|
---|
113 | if (!cfg.disablelog)
|
---|
114 | fprintf(fp, "\n%s\n>> OSCam << cardserver %s at %s%s\n", line, starttext, ctime(&t), line);
|
---|
115 | }
|
---|
116 | }
|
---|
117 | // according to syslog docu: calling closelog is not necessary and calling openlog multiple times is safe
|
---|
118 | // We use openlog to set the default syslog settings so that it's possible to allow switching syslog on and off
|
---|
119 | openlog("oscam", LOG_NDELAY, LOG_DAEMON);
|
---|
120 |
|
---|
121 | cs_log(">> OSCam << cardserver %s, version " CS_VERSION ", build #" CS_SVN_VERSION " (" CS_OSTYPE ")", starttext);
|
---|
122 | cs_log_config();
|
---|
123 | return(fp <= (FILE *)0);
|
---|
124 | }
|
---|
125 |
|
---|
126 | int32_t cs_init_log(void)
|
---|
127 | {
|
---|
128 | if(logStarted == 0){
|
---|
129 | pthread_mutex_init(&switching_log, NULL);
|
---|
130 | pthread_mutex_init(&loghistory_lock, NULL);
|
---|
131 | }
|
---|
132 | int32_t rc = cs_open_logfiles();
|
---|
133 | logStarted = 1;
|
---|
134 | return rc;
|
---|
135 | }
|
---|
136 |
|
---|
137 | /*
|
---|
138 | This function allows to reinit the in-memory loghistory with a new size.
|
---|
139 | */
|
---|
140 | void cs_reinit_loghist(uint32_t size)
|
---|
141 | {
|
---|
142 | char *tmp, *tmp2;
|
---|
143 | if(size != cfg.loghistorysize){
|
---|
144 | if(cs_malloc(&tmp, size, -1)){
|
---|
145 | cs_lock(&loghistory_lock);
|
---|
146 | tmp2 = loghist;
|
---|
147 | // On shrinking, the log is not copied and the order is reversed
|
---|
148 | if(size < cfg.loghistorysize){
|
---|
149 | cfg.loghistorysize = size;
|
---|
150 | cs_sleepms(20); // Monitor or webif may be currently outputting the loghistory but don't use locking so we sleep a bit...
|
---|
151 | loghistptr = tmp;
|
---|
152 | loghist = tmp;
|
---|
153 | } else {
|
---|
154 | if(loghist){
|
---|
155 | memcpy(tmp, loghist, cfg.loghistorysize);
|
---|
156 | loghistptr = tmp + (loghistptr - loghist);
|
---|
157 | } else loghistptr = tmp;
|
---|
158 | loghist = tmp;
|
---|
159 | cs_sleepms(20); // Monitor or webif may be currently outputting the loghistory but don't use locking so we sleep a bit...
|
---|
160 | cfg.loghistorysize = size;
|
---|
161 | }
|
---|
162 | cs_unlock(&loghistory_lock);
|
---|
163 | if(tmp2 != NULL) add_garbage(tmp2);
|
---|
164 | }
|
---|
165 | }
|
---|
166 | }
|
---|
167 |
|
---|
168 | static void get_log_header(int32_t m, char *txt)
|
---|
169 | {
|
---|
170 | struct s_client *cl = cur_client();
|
---|
171 | pthread_t thread = cl?cl->thread:0;
|
---|
172 | if(m)
|
---|
173 | snprintf(txt, LOG_BUF_SIZE, "%8X %c ",(unsigned int) thread, cl?cl->typ:' ');
|
---|
174 | else
|
---|
175 | snprintf(txt, LOG_BUF_SIZE, "%8X%-3.3s",(unsigned int) thread, "");
|
---|
176 | }
|
---|
177 |
|
---|
178 | static void write_to_log(char *txt)
|
---|
179 | {
|
---|
180 | //flag = -1 is old behaviour, before implementation of debug_nolf (=debug no line feed)
|
---|
181 | //
|
---|
182 | time_t t;
|
---|
183 | struct tm lt;
|
---|
184 | char sbuf[16];
|
---|
185 | char log_buf[700];
|
---|
186 | struct s_client *cur_cl = cur_client();
|
---|
187 |
|
---|
188 | // get_log_header(flag, sbuf);
|
---|
189 | // memcpy(txt, sbuf, 11);
|
---|
190 |
|
---|
191 | #ifdef CS_ANTICASC
|
---|
192 | if (cfg.logtosyslog && cur_cl && cur_cl->typ != 'a') // system-logfile
|
---|
193 | #else
|
---|
194 | if (cfg.logtosyslog) // system-logfile
|
---|
195 | #endif
|
---|
196 | syslog(LOG_INFO, "%s", txt);
|
---|
197 |
|
---|
198 | time(&t);
|
---|
199 | localtime_r(&t, <);
|
---|
200 |
|
---|
201 | snprintf(log_buf, sizeof(log_buf), "[LOG000]%4d/%02d/%02d %2d:%02d:%02d %s\n",
|
---|
202 | lt.tm_year+1900, lt.tm_mon+1, lt.tm_mday, lt.tm_hour, lt.tm_min, lt.tm_sec, txt);
|
---|
203 |
|
---|
204 | cs_write_log(log_buf + 8);
|
---|
205 |
|
---|
206 | if (loghist) {
|
---|
207 | char *usrtxt = NULL;
|
---|
208 |
|
---|
209 | if (!cur_cl)
|
---|
210 | usrtxt = "undef";
|
---|
211 | else {
|
---|
212 | switch(cur_cl->typ) {
|
---|
213 | case 'c':
|
---|
214 | case 'm':
|
---|
215 | usrtxt = cur_cl->account ? cur_cl->account->usr : "";
|
---|
216 | break;
|
---|
217 | case 'p':
|
---|
218 | case 'r':
|
---|
219 | usrtxt = cur_cl->reader ? cur_cl->reader->label : "";
|
---|
220 | break;
|
---|
221 | default:
|
---|
222 | usrtxt = "server";
|
---|
223 | break;
|
---|
224 | }
|
---|
225 | }
|
---|
226 |
|
---|
227 | char *target_ptr = NULL;
|
---|
228 | int32_t target_len = strlen(usrtxt) + (strlen(log_buf) - 8) + 1;
|
---|
229 |
|
---|
230 | cs_lock(&loghistory_lock);
|
---|
231 | char *lastpos = loghist + (cfg.loghistorysize) - 1;
|
---|
232 | if (!loghistptr)
|
---|
233 | loghistptr = loghist;
|
---|
234 |
|
---|
235 | if (loghistptr+target_len > lastpos - 1) {
|
---|
236 | *loghistptr='\0';
|
---|
237 | loghistptr=loghist + target_len + 1;
|
---|
238 | *loghistptr='\0';
|
---|
239 | target_ptr=loghist;
|
---|
240 | } else {
|
---|
241 | target_ptr = loghistptr;
|
---|
242 | loghistptr=loghistptr + target_len + 1;
|
---|
243 | *loghistptr='\0';
|
---|
244 | }
|
---|
245 | cs_unlock(&loghistory_lock);
|
---|
246 |
|
---|
247 | snprintf(target_ptr, target_len + 1, "%s\t%s", usrtxt, log_buf + 8);
|
---|
248 | }
|
---|
249 |
|
---|
250 | struct s_client *cl;
|
---|
251 | for (cl=first_client; cl ; cl=cl->next) {
|
---|
252 | if ((cl->typ == 'm') && (cl->monlvl>0) && cl->log) //this variable is only initialized for cl->typ = 'm'
|
---|
253 | {
|
---|
254 | if (cl->monlvl<2) {
|
---|
255 | if (cur_cl && (cur_cl->typ != 'c') && (cur_cl->typ != 'm'))
|
---|
256 | continue;
|
---|
257 | if (cur_cl && cur_cl->account && cl->account && strcmp(cur_cl->account->usr, cl->account->usr))
|
---|
258 | continue;
|
---|
259 | }
|
---|
260 | snprintf(sbuf, sizeof(sbuf), "%03d", cl->logcounter);
|
---|
261 | cl->logcounter = (cl->logcounter+1) % 1000;
|
---|
262 | memcpy(log_buf + 4, sbuf, 3);
|
---|
263 | monitor_send_idx(cl, log_buf);
|
---|
264 | }
|
---|
265 | }
|
---|
266 | }
|
---|
267 |
|
---|
268 | void cs_log(const char *fmt,...)
|
---|
269 | {
|
---|
270 | char log_txt[LOG_BUF_SIZE];
|
---|
271 | get_log_header(1, log_txt);
|
---|
272 | va_list params;
|
---|
273 | va_start(params, fmt);
|
---|
274 | vsnprintf(log_txt+11, sizeof(log_txt) - 11, fmt, params);
|
---|
275 | va_end(params);
|
---|
276 | write_to_log(log_txt);
|
---|
277 | }
|
---|
278 |
|
---|
279 | void cs_close_log(void)
|
---|
280 | {
|
---|
281 | if (!fp) return;
|
---|
282 | fclose(fp);
|
---|
283 | fp=(FILE *)0;
|
---|
284 | }
|
---|
285 | #ifdef WITH_DEBUG
|
---|
286 | void cs_debug_mask(uint16_t mask, const char *fmt,...)
|
---|
287 | {
|
---|
288 | char log_txt[LOG_BUF_SIZE];
|
---|
289 | if (cs_dblevel & mask)
|
---|
290 | {
|
---|
291 | get_log_header(1, log_txt);
|
---|
292 | va_list params;
|
---|
293 | va_start(params, fmt);
|
---|
294 | vsnprintf(log_txt+11, sizeof(log_txt) - 11, fmt, params);
|
---|
295 | va_end(params);
|
---|
296 | write_to_log(log_txt);
|
---|
297 | }
|
---|
298 | }
|
---|
299 | #endif
|
---|
300 | void cs_dump(const uchar *buf, int32_t n, char *fmt, ...)
|
---|
301 | {
|
---|
302 | char log_txt[LOG_BUF_SIZE];
|
---|
303 | int32_t i;
|
---|
304 |
|
---|
305 | if( fmt )
|
---|
306 | {
|
---|
307 | get_log_header(1, log_txt);
|
---|
308 | va_list params;
|
---|
309 | va_start(params, fmt);
|
---|
310 | vsnprintf(log_txt+11, sizeof(log_txt) - 11, fmt, params);
|
---|
311 | va_end(params);
|
---|
312 | write_to_log(log_txt);
|
---|
313 | //printf("LOG: %s\n", txt); fflush(stdout);
|
---|
314 | }
|
---|
315 |
|
---|
316 | for( i=0; i<n; i+=16 )
|
---|
317 | {
|
---|
318 | get_log_header(0, log_txt);
|
---|
319 | snprintf(log_txt+11, sizeof(log_txt) - 11, "%s", cs_hexdump(1, buf+i, (n-i>16) ? 16 : n-i));
|
---|
320 | write_to_log(log_txt);
|
---|
321 | }
|
---|
322 | }
|
---|
323 | #ifdef WITH_DEBUG
|
---|
324 | void cs_ddump_mask(uint16_t mask, const uchar *buf, int32_t n, char *fmt, ...)
|
---|
325 | {
|
---|
326 |
|
---|
327 | char log_txt[LOG_BUF_SIZE];
|
---|
328 | int32_t i;
|
---|
329 | if ((mask & cs_dblevel) && (fmt))
|
---|
330 | {
|
---|
331 | get_log_header(1, log_txt);
|
---|
332 | va_list params;
|
---|
333 | va_start(params, fmt);
|
---|
334 | vsnprintf(log_txt+11, sizeof(log_txt) - 11, fmt, params);
|
---|
335 | va_end(params);
|
---|
336 | write_to_log(log_txt);
|
---|
337 | //printf("LOG: %s\n", txt); fflush(stdout);
|
---|
338 | }
|
---|
339 | if (mask & cs_dblevel)
|
---|
340 | {
|
---|
341 | for (i=0; i<n; i+=16)
|
---|
342 | {
|
---|
343 | get_log_header(0, log_txt);
|
---|
344 | snprintf(log_txt+11, sizeof(log_txt) - 11, "%s", cs_hexdump(1, buf+i, (n-i>16) ? 16 : n-i));
|
---|
345 | write_to_log(log_txt);
|
---|
346 | }
|
---|
347 | }
|
---|
348 | }
|
---|
349 | #endif
|
---|
350 | int32_t cs_init_statistics(void)
|
---|
351 | {
|
---|
352 | if ((!fps) && (cfg.usrfile != NULL))
|
---|
353 | {
|
---|
354 | if ((fps=fopen(cfg.usrfile, "a+"))<=(FILE *)0)
|
---|
355 | {
|
---|
356 | fps=(FILE *)0;
|
---|
357 | cs_log("couldn't open statistics file: %s", cfg.usrfile);
|
---|
358 | }
|
---|
359 | }
|
---|
360 | return(fps<=(FILE *)0);
|
---|
361 | }
|
---|
362 |
|
---|
363 | void cs_statistics(struct s_client * client)
|
---|
364 | {
|
---|
365 | if (!cfg.disableuserfile){
|
---|
366 | time_t t;
|
---|
367 | struct tm lt;
|
---|
368 | char buf[LOG_BUF_SIZE];
|
---|
369 |
|
---|
370 | float cwps;
|
---|
371 |
|
---|
372 | time(&t);
|
---|
373 | localtime_r(&t, <);
|
---|
374 | if (client->cwfound+client->cwnot>0)
|
---|
375 | {
|
---|
376 | cwps=client->last-client->login;
|
---|
377 | cwps/=client->cwfound+client->cwnot;
|
---|
378 | }
|
---|
379 | else
|
---|
380 | cwps=0;
|
---|
381 |
|
---|
382 | char *channel ="";
|
---|
383 | if(cfg.mon_appendchaninfo)
|
---|
384 | channel = get_servicename(client, client->last_srvid,client->last_caid);
|
---|
385 |
|
---|
386 | int32_t lsec;
|
---|
387 | if ((client->last_caid == 0xFFFF) && (client->last_srvid == 0xFFFF))
|
---|
388 | lsec = client->last - client->login; //client leave calc total duration
|
---|
389 | else
|
---|
390 | lsec = client->last - client->lastswitch;
|
---|
391 |
|
---|
392 | int32_t secs = 0, fullmins = 0, mins = 0, fullhours = 0;
|
---|
393 |
|
---|
394 | if((lsec > 0) && (lsec < 1000000)) {
|
---|
395 | secs = lsec % 60;
|
---|
396 | if (lsec > 60) {
|
---|
397 | fullmins = lsec / 60;
|
---|
398 | mins = fullmins % 60;
|
---|
399 | if(fullmins > 60) {
|
---|
400 | fullhours = fullmins / 60;
|
---|
401 | }
|
---|
402 | }
|
---|
403 | }
|
---|
404 |
|
---|
405 | /* statistics entry start with 's' to filter it out on other end of pipe
|
---|
406 | * so we can use the same Pipe as Log
|
---|
407 | */
|
---|
408 | snprintf(buf, sizeof(buf), "s%02d.%02d.%02d %02d:%02d:%02d %3.1f %s %s %d %d %d %d %d %d %d %ld %ld %02d:%02d:%02d %s %04X:%04X %s\n",
|
---|
409 | lt.tm_mday, lt.tm_mon+1, lt.tm_year%100,
|
---|
410 | lt.tm_hour, lt.tm_min, lt.tm_sec, cwps,
|
---|
411 | client->account->usr,
|
---|
412 | cs_inet_ntoa(client->ip),
|
---|
413 | client->port,
|
---|
414 | client->cwfound,
|
---|
415 | client->cwcache,
|
---|
416 | client->cwnot,
|
---|
417 | client->cwignored,
|
---|
418 | client->cwtout,
|
---|
419 | client->cwtun,
|
---|
420 | client->login,
|
---|
421 | client->last,
|
---|
422 | fullhours, mins, secs,
|
---|
423 | ph[client->ctyp].desc,
|
---|
424 | client->last_caid,
|
---|
425 | client->last_srvid,
|
---|
426 | channel);
|
---|
427 |
|
---|
428 | cs_write_log(buf);
|
---|
429 | }
|
---|
430 | }
|
---|