1 | #include "globals.h"
|
---|
2 | #include <syslog.h>
|
---|
3 | #include "module-anticasc.h"
|
---|
4 | #include "module-monitor.h"
|
---|
5 | #include "oscam-client.h"
|
---|
6 | #include "oscam-garbage.h"
|
---|
7 | #include "oscam-lock.h"
|
---|
8 | #include "oscam-log.h"
|
---|
9 | #include "oscam-net.h"
|
---|
10 | #include "oscam-string.h"
|
---|
11 | #include "oscam-time.h"
|
---|
12 |
|
---|
13 | // Do not allow log_list to grow bigger than that many entries
|
---|
14 | #define MAX_LOG_LIST_BACKLOG 10000
|
---|
15 |
|
---|
16 | extern char *syslog_ident;
|
---|
17 | extern int32_t exit_oscam;
|
---|
18 |
|
---|
19 | char *LOG_LIST = "log_list";
|
---|
20 | int8_t logStarted = 0;
|
---|
21 |
|
---|
22 | static FILE *fp;
|
---|
23 | static FILE *fps;
|
---|
24 | static LLIST *log_list;
|
---|
25 | static bool log_running;
|
---|
26 | static int log_list_queued;
|
---|
27 | static pthread_t log_thread;
|
---|
28 | static pthread_cond_t log_thread_sleep_cond;
|
---|
29 | static pthread_mutex_t log_thread_sleep_cond_mutex;
|
---|
30 | static int32_t syslog_socket = -1;
|
---|
31 | static struct sockaddr_in syslog_addr;
|
---|
32 |
|
---|
33 |
|
---|
34 | struct s_log
|
---|
35 | {
|
---|
36 | char *txt;
|
---|
37 | uint8_t header_len;
|
---|
38 | uint8_t header_logcount_offset;
|
---|
39 | uint8_t header_date_offset;
|
---|
40 | uint8_t header_time_offset;
|
---|
41 | uint8_t header_info_offset;
|
---|
42 | int8_t direct_log;
|
---|
43 | int8_t cl_typ;
|
---|
44 | char *cl_usr;
|
---|
45 | char *cl_text;
|
---|
46 | };
|
---|
47 |
|
---|
48 | #define LOG_BUF_SIZE 512
|
---|
49 |
|
---|
50 | static void switch_log(char *file, FILE **f, int32_t (*pfinit)(void))
|
---|
51 | {
|
---|
52 | // only 1 thread needs to switch the log; even if anticasc, statistics and normal log are running
|
---|
53 | // at the same time, it is ok to have the other logs switching 1 entry later
|
---|
54 | if(cfg.max_log_size && file)
|
---|
55 | {
|
---|
56 | if(*f != NULL && ftell(*f) >= cfg.max_log_size * 1024)
|
---|
57 | {
|
---|
58 | int32_t rc;
|
---|
59 | char prev_log[strlen(file) + 6];
|
---|
60 | snprintf(prev_log, sizeof(prev_log), "%s-prev", file);
|
---|
61 | fprintf(*f, "switch log file\n");
|
---|
62 | fflush(*f);
|
---|
63 | fclose(*f);
|
---|
64 | *f = (FILE *)0;
|
---|
65 | rc = rename(file, prev_log);
|
---|
66 |
|
---|
67 | if(rc != 0)
|
---|
68 | {
|
---|
69 | fprintf(stderr, "rename(%s, %s) failed (errno=%d %s)\n", file, prev_log, errno, strerror(errno));
|
---|
70 | }
|
---|
71 | else if(pfinit())
|
---|
72 | {
|
---|
73 | fprintf(stderr, "Initialisation of log file failed, continuing without logging thread %8lX. Log will be output to stdout!", (unsigned long)pthread_self());
|
---|
74 | cfg.logtostdout = 1;
|
---|
75 | }
|
---|
76 | }
|
---|
77 | }
|
---|
78 | }
|
---|
79 |
|
---|
80 | void cs_reopen_log(void)
|
---|
81 | {
|
---|
82 | if(cfg.logfile)
|
---|
83 | {
|
---|
84 | if(fp)
|
---|
85 | {
|
---|
86 | fprintf(fp, "flush and re-open log file\n");
|
---|
87 | fflush(fp);
|
---|
88 | fclose(fp);
|
---|
89 | fp = NULL;
|
---|
90 | }
|
---|
91 |
|
---|
92 | if(cs_open_logfiles())
|
---|
93 | {
|
---|
94 | fprintf(stderr, "Initialisation of log file failed, continuing without logging thread %8luX. Log will be output to stdout!", (unsigned long)pthread_self());
|
---|
95 | cfg.logtostdout = 1;
|
---|
96 | }
|
---|
97 | }
|
---|
98 |
|
---|
99 | if(cfg.usrfile)
|
---|
100 | {
|
---|
101 | if(fps)
|
---|
102 | {
|
---|
103 | fprintf(fps, "flush and re-open user log file\n");
|
---|
104 | fflush(fps);
|
---|
105 | fclose(fps);
|
---|
106 | fps = NULL;
|
---|
107 | }
|
---|
108 |
|
---|
109 | if(cs_init_statistics())
|
---|
110 | {
|
---|
111 | fprintf(stderr, "Initialisation of user log file failed, continuing without logging thread %8luX.", (unsigned long)pthread_self());
|
---|
112 | }
|
---|
113 | }
|
---|
114 | }
|
---|
115 |
|
---|
116 | static void cs_write_log(char *txt, int8_t do_flush, uint8_t hdr_date_offset, uint8_t hdr_time_offset)
|
---|
117 | {
|
---|
118 | // filter out entries with leading 's' and forward to statistics
|
---|
119 | if(txt[hdr_date_offset] == 's')
|
---|
120 | {
|
---|
121 | if(fps)
|
---|
122 | {
|
---|
123 | switch_log(cfg.usrfile, &fps, cs_init_statistics);
|
---|
124 | if(fps)
|
---|
125 | {
|
---|
126 | fputs(txt + hdr_date_offset + 1, fps); // remove the leading 's' and write to file
|
---|
127 | if(do_flush) { fflush(fps); }
|
---|
128 | }
|
---|
129 | }
|
---|
130 | }
|
---|
131 | else
|
---|
132 | {
|
---|
133 | if(!cfg.disablelog)
|
---|
134 | {
|
---|
135 | if(fp)
|
---|
136 | {
|
---|
137 | switch_log(cfg.logfile, &fp, cs_open_logfiles); // only call the switch code if lock = 1 is specified as otherwise we are calling it internally
|
---|
138 | if(fp)
|
---|
139 | {
|
---|
140 | fputs(txt + hdr_date_offset, fp);
|
---|
141 | if(do_flush) { fflush(fp); }
|
---|
142 | }
|
---|
143 | }
|
---|
144 |
|
---|
145 | if(cfg.logtostdout)
|
---|
146 | {
|
---|
147 | fputs(txt + hdr_time_offset, stdout);
|
---|
148 | if(do_flush) { fflush(stdout); }
|
---|
149 | }
|
---|
150 | }
|
---|
151 | }
|
---|
152 | }
|
---|
153 |
|
---|
154 | static void log_list_flush(void)
|
---|
155 | {
|
---|
156 | if(logStarted == 0)
|
---|
157 | { return; }
|
---|
158 |
|
---|
159 | SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond);
|
---|
160 | int32_t i = 0;
|
---|
161 | while(ll_count(log_list) > 0 && i < 200)
|
---|
162 | {
|
---|
163 | cs_sleepms(5);
|
---|
164 | ++i;
|
---|
165 | }
|
---|
166 | }
|
---|
167 |
|
---|
168 | static void log_list_add(struct s_log *log)
|
---|
169 | {
|
---|
170 | if(logStarted == 0)
|
---|
171 | { return; }
|
---|
172 |
|
---|
173 | int32_t count = ll_count(log_list);
|
---|
174 | log_list_queued++;
|
---|
175 | if(count < MAX_LOG_LIST_BACKLOG)
|
---|
176 | {
|
---|
177 | ll_append(log_list, log);
|
---|
178 | }
|
---|
179 | else // We have too much backlog
|
---|
180 | {
|
---|
181 | NULLFREE(log->txt);
|
---|
182 | NULLFREE(log);
|
---|
183 | cs_write_log("-------------> Too much data in log_list, dropping log message.\n", 1, 0, 0);
|
---|
184 | }
|
---|
185 | SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond);
|
---|
186 | }
|
---|
187 |
|
---|
188 | static void cs_write_log_int(char *txt)
|
---|
189 | {
|
---|
190 | if(exit_oscam == 1)
|
---|
191 | {
|
---|
192 | cs_write_log(txt, 1, 0, 0);
|
---|
193 | }
|
---|
194 | else
|
---|
195 | {
|
---|
196 | char *newtxt = cs_strdup(txt);
|
---|
197 | if(!newtxt)
|
---|
198 | { return; }
|
---|
199 | struct s_log *log;
|
---|
200 | if(!cs_malloc(&log, sizeof(struct s_log)))
|
---|
201 | {
|
---|
202 | NULLFREE(newtxt);
|
---|
203 | return;
|
---|
204 | }
|
---|
205 | log->txt = newtxt;
|
---|
206 | log->header_len = 0;
|
---|
207 | log->direct_log = 1;
|
---|
208 | log_list_add(log);
|
---|
209 | }
|
---|
210 | }
|
---|
211 |
|
---|
212 | int32_t cs_open_logfiles(void)
|
---|
213 | {
|
---|
214 | char *starttext;
|
---|
215 | if(logStarted) { starttext = "log switched"; }
|
---|
216 | else { starttext = "started"; }
|
---|
217 | if(!fp && cfg.logfile) // log to file
|
---|
218 | {
|
---|
219 | if((fp = fopen(cfg.logfile, "a+")) <= (FILE *)0)
|
---|
220 | {
|
---|
221 | fp = (FILE *)0;
|
---|
222 | fprintf(stderr, "couldn't open logfile: %s (errno %d %s)\n", cfg.logfile, errno, strerror(errno));
|
---|
223 | }
|
---|
224 | else
|
---|
225 | {
|
---|
226 | char line[80];
|
---|
227 | memset(line, '-', sizeof(line));
|
---|
228 | line[(sizeof(line) / sizeof(char)) - 1] = '\0';
|
---|
229 | time_t walltime = cs_time();
|
---|
230 | if(!cfg.disablelog)
|
---|
231 | {
|
---|
232 | char buf[28];
|
---|
233 | cs_ctime_r(&walltime, buf);
|
---|
234 | fprintf(fp, "\n%s\n>> OSCam << cardserver %s at %s%s\n", line, starttext, buf, line);
|
---|
235 | }
|
---|
236 | }
|
---|
237 | }
|
---|
238 | // according to syslog docu: calling closelog is not necessary and calling openlog multiple times is safe
|
---|
239 | // We use openlog to set the default syslog settings so that it's possible to allow switching syslog on and off
|
---|
240 | openlog(syslog_ident, LOG_NDELAY | LOG_PID, LOG_DAEMON);
|
---|
241 | cs_log(">> OSCam << cardserver %s, version " CS_VERSION ", build r" CS_SVN_VERSION " (" CS_TARGET ")", starttext);
|
---|
242 |
|
---|
243 | return (fp <= (FILE *)0);
|
---|
244 | }
|
---|
245 |
|
---|
246 | #if defined(WEBIF) || defined(MODULE_MONITOR)
|
---|
247 |
|
---|
248 | static uint64_t counter = 0;
|
---|
249 | LLIST *log_history = NULL;
|
---|
250 |
|
---|
251 | /*
|
---|
252 | This function allows to reinit the in-memory loghistory with a new size.
|
---|
253 | */
|
---|
254 | void cs_reinit_loghist(uint32_t size)
|
---|
255 | {
|
---|
256 | if(cfg.loghistorylines != size)
|
---|
257 | {
|
---|
258 | cfg.loghistorylines = size;
|
---|
259 | }
|
---|
260 | }
|
---|
261 | #endif
|
---|
262 |
|
---|
263 | static struct timeb log_ts;
|
---|
264 |
|
---|
265 | static uint8_t get_log_header(char *txt, int32_t txt_size, uint8_t* hdr_logcount_offset,
|
---|
266 | uint8_t* hdr_date_offset, uint8_t* hdr_time_offset, uint8_t* hdr_info_offset)
|
---|
267 | {
|
---|
268 | struct s_client *cl = cur_client();
|
---|
269 | struct tm lt;
|
---|
270 | int32_t tmp;
|
---|
271 |
|
---|
272 | cs_ftime(&log_ts);
|
---|
273 | time_t walltime = cs_walltime(&log_ts);
|
---|
274 | localtime_r(&walltime, <);
|
---|
275 |
|
---|
276 | tmp = snprintf(txt, txt_size, "[LOG000]%04d/%02d/%02d %02d:%02d:%02d %08X %c ",
|
---|
277 | lt.tm_year + 1900,
|
---|
278 | lt.tm_mon + 1,
|
---|
279 | lt.tm_mday,
|
---|
280 | lt.tm_hour,
|
---|
281 | lt.tm_min,
|
---|
282 | lt.tm_sec,
|
---|
283 | cl ? cl->tid : 0,
|
---|
284 | cl ? cl->typ : ' '
|
---|
285 | );
|
---|
286 |
|
---|
287 | if(tmp == 39)
|
---|
288 | {
|
---|
289 | if(hdr_logcount_offset != NULL)
|
---|
290 | {
|
---|
291 | // depends on snprintf(...) format
|
---|
292 | (*hdr_logcount_offset) = 4;
|
---|
293 | }
|
---|
294 |
|
---|
295 | if(hdr_date_offset != NULL)
|
---|
296 | {
|
---|
297 | // depends on snprintf(...) format
|
---|
298 | (*hdr_date_offset) = *hdr_logcount_offset + 4;
|
---|
299 | }
|
---|
300 |
|
---|
301 | if(hdr_time_offset != NULL)
|
---|
302 | {
|
---|
303 | // depends on snprintf(...) format
|
---|
304 | (*hdr_time_offset) = *hdr_date_offset + 11;
|
---|
305 | }
|
---|
306 |
|
---|
307 | if(hdr_info_offset != NULL)
|
---|
308 | {
|
---|
309 | // depends on snprintf(...) format
|
---|
310 | (*hdr_info_offset) = *hdr_time_offset + 9;
|
---|
311 | }
|
---|
312 |
|
---|
313 | return (uint8_t)tmp;
|
---|
314 | }
|
---|
315 |
|
---|
316 | if(hdr_logcount_offset != NULL)
|
---|
317 | {
|
---|
318 | (*hdr_logcount_offset) = 0;
|
---|
319 | }
|
---|
320 |
|
---|
321 | if(hdr_date_offset != NULL)
|
---|
322 | {
|
---|
323 | (*hdr_date_offset) = 0;
|
---|
324 | }
|
---|
325 |
|
---|
326 | if(hdr_time_offset != NULL)
|
---|
327 | {
|
---|
328 | (*hdr_time_offset) = 0;
|
---|
329 | }
|
---|
330 |
|
---|
331 | if(hdr_info_offset != NULL)
|
---|
332 | {
|
---|
333 | (*hdr_info_offset) = 0;
|
---|
334 | }
|
---|
335 |
|
---|
336 | return 0;
|
---|
337 | }
|
---|
338 |
|
---|
339 | static void write_to_log(char *txt, struct s_log *log, int8_t do_flush)
|
---|
340 | {
|
---|
341 | if(logStarted == 0)
|
---|
342 | { return; }
|
---|
343 |
|
---|
344 | (void)log; // Prevent warning when WEBIF, MODULE_MONITOR and CS_ANTICASC are disabled
|
---|
345 |
|
---|
346 | // anticascading messages go to their own log
|
---|
347 | if (!anticasc_logging(txt + log->header_date_offset))
|
---|
348 | {
|
---|
349 | if(cfg.logtosyslog)
|
---|
350 | {
|
---|
351 | syslog(LOG_INFO, "%s", txt + log->header_info_offset);
|
---|
352 | }
|
---|
353 |
|
---|
354 | if (cfg.sysloghost != NULL && syslog_socket != -1)
|
---|
355 | {
|
---|
356 | char tmp[128 + LOG_BUF_SIZE];
|
---|
357 | static char hostname[64];
|
---|
358 | static uint8_t have_hostname = 0;
|
---|
359 | time_t walltime;
|
---|
360 | struct tm lt;
|
---|
361 | char timebuf[32];
|
---|
362 |
|
---|
363 | if(!have_hostname)
|
---|
364 | {
|
---|
365 | if(gethostname(hostname, 64) != 0)
|
---|
366 | {
|
---|
367 | cs_strncpy(hostname, "unknown", 64);
|
---|
368 | }
|
---|
369 |
|
---|
370 | have_hostname = 1;
|
---|
371 | }
|
---|
372 |
|
---|
373 | walltime = cs_time();
|
---|
374 | localtime_r(&walltime, <);
|
---|
375 |
|
---|
376 | if(strftime(timebuf, 32, "%b %d %H:%M:%S", <) == 0)
|
---|
377 | {
|
---|
378 | cs_strncpy(timebuf, "unknown", 32);
|
---|
379 | }
|
---|
380 |
|
---|
381 | snprintf(tmp, sizeof(tmp), "%s %s oscam[%u]: %s", timebuf, hostname, getpid(), txt + log->header_info_offset);
|
---|
382 | sendto(syslog_socket, tmp, strlen(tmp), 0, (struct sockaddr*) &syslog_addr, sizeof(syslog_addr));
|
---|
383 | }
|
---|
384 | }
|
---|
385 |
|
---|
386 | strcat(txt, "\n");
|
---|
387 | cs_write_log(txt, do_flush, log->header_date_offset, log->header_time_offset);
|
---|
388 |
|
---|
389 | #if defined(WEBIF) || defined(MODULE_MONITOR)
|
---|
390 | if(!exit_oscam && cfg.loghistorylines && log_history)
|
---|
391 | {
|
---|
392 | struct s_log_history *hist;
|
---|
393 |
|
---|
394 | while((uint32_t)ll_count(log_history) >= cfg.loghistorylines)
|
---|
395 | {
|
---|
396 | hist = ll_remove_first(log_history);
|
---|
397 | if(hist)
|
---|
398 | {
|
---|
399 | add_garbage(hist->txt);
|
---|
400 | add_garbage(hist);
|
---|
401 | hist = NULL;
|
---|
402 | }
|
---|
403 | }
|
---|
404 |
|
---|
405 | if(cs_malloc(&hist, sizeof(struct s_log_history)))
|
---|
406 | {
|
---|
407 | int32_t target_len = strlen(log->cl_text) + strlen(txt+log->header_date_offset) + 1;
|
---|
408 |
|
---|
409 | if(cs_malloc(&hist->txt, sizeof(char) * (target_len + 1)))
|
---|
410 | {
|
---|
411 | hist->counter = counter++;
|
---|
412 | snprintf(hist->txt, target_len + 1, "%s\t%s", log->cl_text, txt + log->header_date_offset);
|
---|
413 |
|
---|
414 | ll_append(log_history, hist);
|
---|
415 | }
|
---|
416 | else
|
---|
417 | {
|
---|
418 | NULLFREE(hist);
|
---|
419 | }
|
---|
420 | }
|
---|
421 | }
|
---|
422 | #endif
|
---|
423 |
|
---|
424 | #if defined(MODULE_MONITOR)
|
---|
425 | char sbuf[16];
|
---|
426 | struct s_client *cl;
|
---|
427 | for(cl = first_client; cl ; cl = cl->next)
|
---|
428 | {
|
---|
429 | if((cl->typ == 'm') && (cl->monlvl > 0) && cl->log) // this variable is only initialized for cl->typ = 'm'
|
---|
430 | {
|
---|
431 | if(cl->monlvl < 2)
|
---|
432 | {
|
---|
433 | if(log->cl_typ != 'c' && log->cl_typ != 'm')
|
---|
434 | { continue; }
|
---|
435 |
|
---|
436 | if(log->cl_usr && cl->account && strcmp(log->cl_usr, cl->account->usr))
|
---|
437 | { continue; }
|
---|
438 | }
|
---|
439 |
|
---|
440 | if(log->header_len > 0)
|
---|
441 | {
|
---|
442 | snprintf(sbuf, sizeof(sbuf), "%03d", cl->logcounter);
|
---|
443 | cl->logcounter = (cl->logcounter + 1) % 1000;
|
---|
444 | memcpy(txt + log->header_logcount_offset, sbuf, 3);
|
---|
445 | monitor_send_idx(cl, txt);
|
---|
446 | }
|
---|
447 | else
|
---|
448 | {
|
---|
449 | char tmp_log[8+LOG_BUF_SIZE];
|
---|
450 | snprintf(tmp_log, sizeof(tmp_log), "[LOG%03d]%s", cl->logcounter, txt);
|
---|
451 | cl->logcounter = (cl->logcounter + 1) % 1000;
|
---|
452 | monitor_send_idx(cl, tmp_log);
|
---|
453 | }
|
---|
454 | }
|
---|
455 | }
|
---|
456 | #endif
|
---|
457 | }
|
---|
458 |
|
---|
459 | static void write_to_log_int(char *txt, uint8_t header_len, uint8_t hdr_logcount_offset, uint8_t hdr_date_offset, uint8_t hdr_time_offset, uint8_t hdr_info_offset)
|
---|
460 | {
|
---|
461 | #if !defined(WEBIF) && !defined(MODULE_MONITOR)
|
---|
462 | if(cfg.disablelog) { return; }
|
---|
463 | #endif
|
---|
464 | char *newtxt = cs_strdup(txt);
|
---|
465 | if(!newtxt)
|
---|
466 | { return; }
|
---|
467 |
|
---|
468 | struct s_log *log;
|
---|
469 | if(!cs_malloc(&log, sizeof(struct s_log)))
|
---|
470 | {
|
---|
471 | NULLFREE(newtxt);
|
---|
472 | return;
|
---|
473 | }
|
---|
474 |
|
---|
475 | log->txt = newtxt;
|
---|
476 | log->header_len = header_len;
|
---|
477 | log->header_logcount_offset = hdr_logcount_offset;
|
---|
478 | log->header_date_offset = hdr_date_offset;
|
---|
479 | log->header_time_offset = hdr_time_offset;
|
---|
480 | log->header_info_offset = hdr_info_offset;
|
---|
481 | log->direct_log = 0;
|
---|
482 | struct s_client *cl = cur_client();
|
---|
483 | log->cl_usr = "";
|
---|
484 |
|
---|
485 | if(!cl)
|
---|
486 | {
|
---|
487 | log->cl_text = "undef";
|
---|
488 | log->cl_typ = ' ';
|
---|
489 | }
|
---|
490 | else
|
---|
491 | {
|
---|
492 | switch(cl->typ)
|
---|
493 | {
|
---|
494 | case 'c':
|
---|
495 | case 'm':
|
---|
496 | if(cl->account)
|
---|
497 | {
|
---|
498 | log->cl_text = cl->account->usr;
|
---|
499 | log->cl_usr = cl->account->usr;
|
---|
500 | }
|
---|
501 | else
|
---|
502 | {
|
---|
503 | log->cl_text = "";
|
---|
504 | }
|
---|
505 | break;
|
---|
506 |
|
---|
507 | case 'p':
|
---|
508 | case 'r':
|
---|
509 | log->cl_text = cl->reader ? cl->reader->label : "";
|
---|
510 | break;
|
---|
511 |
|
---|
512 | default:
|
---|
513 | log->cl_text = "server";
|
---|
514 | break;
|
---|
515 | }
|
---|
516 | log->cl_typ = cl->typ;
|
---|
517 | }
|
---|
518 |
|
---|
519 | if(exit_oscam == 1 || cfg.disablelog) // Exit or log disabled. if disabled, just display on webif/monitor
|
---|
520 | {
|
---|
521 | char buf[LOG_BUF_SIZE];
|
---|
522 | cs_strncpy(buf, log->txt, LOG_BUF_SIZE);
|
---|
523 | write_to_log(buf, log, 1);
|
---|
524 | NULLFREE(log->txt);
|
---|
525 | NULLFREE(log);
|
---|
526 | }
|
---|
527 | else
|
---|
528 | { log_list_add(log); }
|
---|
529 | }
|
---|
530 |
|
---|
531 | static pthread_mutex_t log_mutex;
|
---|
532 | static char log_txt[LOG_BUF_SIZE];
|
---|
533 | static char dupl[LOG_BUF_SIZE / 4];
|
---|
534 | static char last_log_txt[LOG_BUF_SIZE];
|
---|
535 | static struct timeb last_log_ts;
|
---|
536 | static unsigned int last_log_duplicates;
|
---|
537 |
|
---|
538 | static void __cs_log_check_duplicates(uint8_t hdr_len, uint8_t hdr_logcount_offset, uint8_t hdr_date_offset, uint8_t hdr_time_offset, uint8_t hdr_info_offset)
|
---|
539 | {
|
---|
540 | bool repeated_line = strcmp(last_log_txt, log_txt + hdr_len) == 0;
|
---|
541 | if (last_log_duplicates > 0)
|
---|
542 | {
|
---|
543 | if (!cs_valid_time(&last_log_ts)) // Must be initialized once
|
---|
544 | last_log_ts = log_ts;
|
---|
545 |
|
---|
546 | // Report duplicated lines when the new log line is different
|
---|
547 | // than the old or 60 seconds have passed.
|
---|
548 | int64_t gone = comp_timeb(&log_ts, &last_log_ts);
|
---|
549 |
|
---|
550 | if (!repeated_line || gone >= 60 * 1000)
|
---|
551 | {
|
---|
552 | uint8_t dupl_hdr_logcount_offset = 0, dupl_hdr_date_offset = 0, dupl_hdr_time_offset = 0, dupl_hdr_info_offset = 0;
|
---|
553 | uint8_t dupl_header_len = get_log_header(dupl, sizeof(dupl), &dupl_hdr_logcount_offset, &dupl_hdr_date_offset, &dupl_hdr_time_offset, &dupl_hdr_info_offset);
|
---|
554 | snprintf(dupl + dupl_header_len - 1, sizeof(dupl) - dupl_header_len, " (-) -- Skipped %u duplicated log lines --", last_log_duplicates);
|
---|
555 | write_to_log_int(dupl, dupl_header_len, dupl_hdr_logcount_offset, dupl_hdr_date_offset, dupl_hdr_time_offset, dupl_hdr_info_offset);
|
---|
556 | last_log_duplicates = 0;
|
---|
557 | last_log_ts = log_ts;
|
---|
558 | }
|
---|
559 | }
|
---|
560 |
|
---|
561 | if (!repeated_line)
|
---|
562 | {
|
---|
563 | memcpy(last_log_txt, log_txt + hdr_len, LOG_BUF_SIZE - hdr_len);
|
---|
564 | write_to_log_int(log_txt, hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset);
|
---|
565 | }
|
---|
566 | else
|
---|
567 | {
|
---|
568 | last_log_duplicates++;
|
---|
569 | }
|
---|
570 | }
|
---|
571 |
|
---|
572 | #define __init_log_prefix(fmt) \
|
---|
573 | uint8_t hdr_logcount_offset = 0, hdr_date_offset = 0, hdr_time_offset = 0, hdr_info_offset = 0; \
|
---|
574 | uint8_t hdr_len = get_log_header(log_txt, sizeof(log_txt), &hdr_logcount_offset, &hdr_date_offset, &hdr_time_offset, &hdr_info_offset); \
|
---|
575 | int32_t log_prefix_len = 0; \
|
---|
576 | do { \
|
---|
577 | if (log_prefix) { \
|
---|
578 | char _lp[16]; \
|
---|
579 | snprintf(_lp, sizeof(_lp), "(%s)", log_prefix); \
|
---|
580 | log_prefix_len = snprintf(log_txt + hdr_len, sizeof(log_txt) - hdr_len, fmt, _lp); \
|
---|
581 | } \
|
---|
582 | } while(0)
|
---|
583 |
|
---|
584 | #define __do_log() \
|
---|
585 | do { \
|
---|
586 | va_list params; \
|
---|
587 | va_start(params, fmt); \
|
---|
588 | __init_log_prefix("%10s "); \
|
---|
589 | vsnprintf(log_txt + hdr_len + log_prefix_len, sizeof(log_txt) - (hdr_len + log_prefix_len), fmt, params); \
|
---|
590 | va_end(params); \
|
---|
591 | if (cfg.logduplicatelines) \
|
---|
592 | { \
|
---|
593 | memcpy(last_log_txt, log_txt + hdr_len, LOG_BUF_SIZE - hdr_len); \
|
---|
594 | write_to_log_int(log_txt, hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset); \
|
---|
595 | } else { \
|
---|
596 | __cs_log_check_duplicates(hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset); \
|
---|
597 | } \
|
---|
598 | } while(0)
|
---|
599 |
|
---|
600 | void cs_log_txt(const char *log_prefix, const char *fmt, ...)
|
---|
601 | {
|
---|
602 | if(logStarted == 0)
|
---|
603 | { return; }
|
---|
604 |
|
---|
605 | SAFE_MUTEX_LOCK_NOLOG(&log_mutex);
|
---|
606 | __do_log();
|
---|
607 | SAFE_MUTEX_UNLOCK_NOLOG(&log_mutex);
|
---|
608 | }
|
---|
609 |
|
---|
610 | void cs_log_hex(const char *log_prefix, const uint8_t *buf, int32_t n, const char *fmt, ...)
|
---|
611 | {
|
---|
612 | if(logStarted == 0)
|
---|
613 | { return; }
|
---|
614 |
|
---|
615 | SAFE_MUTEX_LOCK_NOLOG(&log_mutex);
|
---|
616 | __do_log();
|
---|
617 | if(buf)
|
---|
618 | {
|
---|
619 | int32_t i;
|
---|
620 | __init_log_prefix("%10s ");
|
---|
621 | for(i = 0; i < n; i += 16)
|
---|
622 | {
|
---|
623 | cs_hexdump(1, buf + i, (n - i > 16) ? 16 : n - i, log_txt + hdr_len + log_prefix_len, sizeof(log_txt) - (hdr_len + log_prefix_len));
|
---|
624 | write_to_log_int(log_txt, hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset);
|
---|
625 | }
|
---|
626 | }
|
---|
627 | SAFE_MUTEX_UNLOCK_NOLOG(&log_mutex);
|
---|
628 | }
|
---|
629 |
|
---|
630 | static void cs_close_log(void)
|
---|
631 | {
|
---|
632 | log_list_flush();
|
---|
633 | if(fp)
|
---|
634 | {
|
---|
635 | fclose(fp);
|
---|
636 | fp = (FILE *)0;
|
---|
637 | }
|
---|
638 | }
|
---|
639 |
|
---|
640 | int32_t cs_init_statistics(void)
|
---|
641 | {
|
---|
642 | if((!fps) && (cfg.usrfile != NULL))
|
---|
643 | {
|
---|
644 | if((fps = fopen(cfg.usrfile, "a+")) <= (FILE *)0)
|
---|
645 | {
|
---|
646 | fps = (FILE *)0;
|
---|
647 | cs_log("couldn't open statistics file: %s", cfg.usrfile);
|
---|
648 | }
|
---|
649 | }
|
---|
650 | return (fps <= (FILE *)0);
|
---|
651 | }
|
---|
652 |
|
---|
653 | void cs_statistics(struct s_client *client)
|
---|
654 | {
|
---|
655 | if(!cfg.disableuserfile)
|
---|
656 | {
|
---|
657 | struct tm lt;
|
---|
658 | char buf[LOG_BUF_SIZE];
|
---|
659 |
|
---|
660 | float cwps;
|
---|
661 |
|
---|
662 | time_t walltime = cs_time();
|
---|
663 | localtime_r(&walltime, <);
|
---|
664 | if(client->cwfound + client->cwnot > 0)
|
---|
665 | {
|
---|
666 | cwps = client->last - client->login;
|
---|
667 | cwps /= client->cwfound + client->cwnot;
|
---|
668 | }
|
---|
669 | else
|
---|
670 | { cwps = 0; }
|
---|
671 |
|
---|
672 | char channame[CS_SERVICENAME_SIZE];
|
---|
673 | get_servicename(client, client->last_srvid, client->last_provid, client->last_caid, channame, sizeof(channame));
|
---|
674 |
|
---|
675 | int32_t lsec;
|
---|
676 | if((client->last_caid == NO_CAID_VALUE) && (client->last_srvid == NO_SRVID_VALUE))
|
---|
677 | { lsec = client->last - client->login; } //client leave calc total duration
|
---|
678 | else
|
---|
679 | { lsec = client->last - client->lastswitch; }
|
---|
680 |
|
---|
681 | int32_t secs = 0, fullmins = 0, mins = 0, fullhours = 0;
|
---|
682 |
|
---|
683 | if((lsec > 0) && (lsec < 1000000))
|
---|
684 | {
|
---|
685 | secs = lsec % 60;
|
---|
686 | if(lsec > 60)
|
---|
687 | {
|
---|
688 | fullmins = lsec / 60;
|
---|
689 | mins = fullmins % 60;
|
---|
690 | if(fullmins > 60)
|
---|
691 | {
|
---|
692 | fullhours = fullmins / 60;
|
---|
693 | }
|
---|
694 | }
|
---|
695 | }
|
---|
696 |
|
---|
697 | /* statistics entry start with 's' to filter it out on other end of pipe
|
---|
698 | * so we can use the same Pipe as Log
|
---|
699 | */
|
---|
700 | 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@%06X:%04X %s\n",
|
---|
701 | lt.tm_mday, lt.tm_mon + 1, lt.tm_year % 100,
|
---|
702 | lt.tm_hour, lt.tm_min, lt.tm_sec, cwps,
|
---|
703 | client->account->usr,
|
---|
704 | cs_inet_ntoa(client->ip),
|
---|
705 | client->port,
|
---|
706 | client->cwfound,
|
---|
707 | client->cwcache,
|
---|
708 | client->cwnot,
|
---|
709 | client->cwignored,
|
---|
710 | client->cwtout,
|
---|
711 | client->cwtun,
|
---|
712 | client->login,
|
---|
713 | client->last,
|
---|
714 | fullhours, mins, secs,
|
---|
715 | get_module(client)->desc,
|
---|
716 | client->last_caid,
|
---|
717 | client->last_provid,
|
---|
718 | client->last_srvid,
|
---|
719 | channame);
|
---|
720 |
|
---|
721 | cs_write_log_int(buf);
|
---|
722 | }
|
---|
723 | }
|
---|
724 |
|
---|
725 | void log_list_thread(void)
|
---|
726 | {
|
---|
727 | char buf[LOG_BUF_SIZE];
|
---|
728 | log_running = 1;
|
---|
729 | set_thread_name(__func__);
|
---|
730 | do
|
---|
731 | {
|
---|
732 | log_list_queued = 0;
|
---|
733 | LL_ITER it = ll_iter_create(log_list);
|
---|
734 | struct s_log *log;
|
---|
735 | while((log = ll_iter_next_remove(&it)))
|
---|
736 | {
|
---|
737 | int8_t do_flush = ll_count(log_list) == 0; // flush on writing last element
|
---|
738 |
|
---|
739 | cs_strncpy(buf, log->txt, LOG_BUF_SIZE);
|
---|
740 | if(log->direct_log)
|
---|
741 | { cs_write_log(buf, do_flush, log->header_date_offset, log->header_time_offset); }
|
---|
742 | else
|
---|
743 | { write_to_log(buf, log, do_flush); }
|
---|
744 | NULLFREE(log->txt);
|
---|
745 | NULLFREE(log);
|
---|
746 | }
|
---|
747 | if(!log_list_queued) // The list is empty, sleep until new data comes in and we are woken up
|
---|
748 | sleepms_on_cond(__func__, &log_thread_sleep_cond_mutex, &log_thread_sleep_cond, 60 * 1000);
|
---|
749 | }
|
---|
750 | while(log_running);
|
---|
751 | ll_destroy(&log_list);
|
---|
752 | }
|
---|
753 |
|
---|
754 | static void init_syslog_socket(void)
|
---|
755 | {
|
---|
756 | if(cfg.sysloghost != NULL && syslog_socket == -1)
|
---|
757 | {
|
---|
758 | IN_ADDR_T in_addr;
|
---|
759 |
|
---|
760 | if ((syslog_socket = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP)) == -1)
|
---|
761 | {
|
---|
762 | perror("Socket create error!");
|
---|
763 | }
|
---|
764 |
|
---|
765 | memset((char *) &syslog_addr, 0, sizeof(syslog_addr));
|
---|
766 | syslog_addr.sin_family = AF_INET;
|
---|
767 | syslog_addr.sin_port = htons(cfg.syslogport);
|
---|
768 | cs_resolve(cfg.sysloghost, &in_addr, NULL, NULL);
|
---|
769 | SIN_GET_ADDR(syslog_addr) = in_addr;
|
---|
770 | }
|
---|
771 | }
|
---|
772 |
|
---|
773 | int32_t cs_init_log(void)
|
---|
774 | {
|
---|
775 | if(logStarted == 0)
|
---|
776 | {
|
---|
777 | init_syslog_socket();
|
---|
778 | SAFE_MUTEX_INIT_NOLOG(&log_mutex, NULL);
|
---|
779 |
|
---|
780 | cs_pthread_cond_init_nolog(__func__, &log_thread_sleep_cond_mutex, &log_thread_sleep_cond);
|
---|
781 |
|
---|
782 | #if defined(WEBIF) || defined(MODULE_MONITOR)
|
---|
783 | log_history = ll_create("log history");
|
---|
784 | #endif
|
---|
785 |
|
---|
786 | log_list = ll_create(LOG_LIST);
|
---|
787 |
|
---|
788 | int32_t ret = start_thread_nolog("logging", (void *)&log_list_thread, NULL, &log_thread, 0, 1);
|
---|
789 | if(ret)
|
---|
790 | {
|
---|
791 | cs_exit(1);
|
---|
792 | }
|
---|
793 |
|
---|
794 | logStarted = 1;
|
---|
795 | }
|
---|
796 |
|
---|
797 | int32_t rc = 0;
|
---|
798 | if(!cfg.disablelog) { rc = cs_open_logfiles(); }
|
---|
799 | logStarted = 1;
|
---|
800 |
|
---|
801 | if(cfg.initial_debuglevel > 0)
|
---|
802 | {
|
---|
803 | cs_dblevel = cfg.initial_debuglevel;
|
---|
804 | cs_log("debug_level=%d", cs_dblevel);
|
---|
805 | }
|
---|
806 |
|
---|
807 | return rc;
|
---|
808 | }
|
---|
809 |
|
---|
810 | void cs_disable_log(int8_t disabled)
|
---|
811 | {
|
---|
812 | if(cfg.disablelog != disabled)
|
---|
813 | {
|
---|
814 | if(disabled && logStarted)
|
---|
815 | {
|
---|
816 | cs_log("Stopping log...");
|
---|
817 | log_list_flush();
|
---|
818 | }
|
---|
819 |
|
---|
820 | cfg.disablelog = disabled;
|
---|
821 | if(disabled)
|
---|
822 | {
|
---|
823 | if(logStarted)
|
---|
824 | {
|
---|
825 | if(syslog_socket != -1)
|
---|
826 | {
|
---|
827 | close(syslog_socket);
|
---|
828 | syslog_socket = -1;
|
---|
829 | }
|
---|
830 |
|
---|
831 | cs_sleepms(20);
|
---|
832 | cs_close_log();
|
---|
833 | }
|
---|
834 | }
|
---|
835 | else
|
---|
836 | {
|
---|
837 | init_syslog_socket();
|
---|
838 | cs_open_logfiles();
|
---|
839 | }
|
---|
840 | }
|
---|
841 | }
|
---|
842 |
|
---|
843 | void log_free(void)
|
---|
844 | {
|
---|
845 | if(syslog_socket != -1)
|
---|
846 | {
|
---|
847 | close(syslog_socket);
|
---|
848 | syslog_socket = -1;
|
---|
849 | }
|
---|
850 |
|
---|
851 | cs_close_log();
|
---|
852 | log_running = 0;
|
---|
853 | SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond);
|
---|
854 | SAFE_THREAD_JOIN_NOLOG(log_thread, NULL);
|
---|
855 | }
|
---|