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"
10 #include "oscam-string.h"
11 #include "oscam-time.h"
13 // Do not allow log_list to grow bigger than that many entries
14 #define MAX_LOG_LIST_BACKLOG 10000
16 extern char *syslog_ident
;
17 extern int32_t exit_oscam
;
19 char *LOG_LIST
= "log_list";
20 int8_t logStarted
= 0;
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 syslog_addr
;
38 uint8_t header_logcount_offset
;
39 uint8_t header_date_offset
;
40 uint8_t header_time_offset
;
41 uint8_t header_info_offset
;
48 #define LOG_BUF_SIZE 512
50 static void switch_log(char *file
, FILE **f
, int32_t (*pfinit
)(void))
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
)
56 if(*f
!= NULL
&& ftell(*f
) >= cfg
.max_log_size
* 1024)
59 char prev_log
[cs_strlen(file
) + 6];
60 snprintf(prev_log
, sizeof(prev_log
), "%s-prev", file
);
61 fprintf(*f
, "switch log file\n");
65 rc
= rename(file
, prev_log
);
69 fprintf(stderr
, "rename(%s, %s) failed (errno=%d %s)\n", file
, prev_log
, errno
, strerror(errno
));
73 fprintf(stderr
, "Initialisation of log file failed, continuing without logging thread %8lX. Log will be output to stdout!", (unsigned long)pthread_self());
80 void cs_reopen_log(void)
86 fprintf(fp
, "flush and re-open log file\n");
92 if(cs_open_logfiles())
94 fprintf(stderr
, "Initialisation of log file failed, continuing without logging thread %8luX. Log will be output to stdout!", (unsigned long)pthread_self());
103 fprintf(fps
, "flush and re-open user log file\n");
109 if(cs_init_statistics())
111 fprintf(stderr
, "Initialisation of user log file failed, continuing without logging thread %8luX.", (unsigned long)pthread_self());
116 static void cs_write_log(char *txt
, int8_t do_flush
, uint8_t hdr_date_offset
, uint8_t hdr_time_offset
)
118 // filter out entries with leading 's' and forward to statistics
119 if(txt
[hdr_date_offset
] == 's')
123 switch_log(cfg
.usrfile
, &fps
, cs_init_statistics
);
126 fputs(txt
+ hdr_date_offset
+ 1, fps
); // remove the leading 's' and write to file
127 if(do_flush
) { fflush(fps
); }
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
140 fputs(txt
+ hdr_date_offset
, fp
);
141 if(do_flush
) { fflush(fp
); }
147 fputs(txt
+ hdr_time_offset
, stdout
);
148 if(do_flush
) { fflush(stdout
); }
154 static void log_list_flush(void)
159 SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond
);
161 while(ll_count(log_list
) > 0 && i
< 200)
168 static void log_list_add(struct s_log
*log
)
173 int32_t count
= ll_count(log_list
);
175 if(count
< MAX_LOG_LIST_BACKLOG
)
177 ll_append(log_list
, log
);
179 else // We have too much backlog
183 cs_write_log("-------------> Too much data in log_list, dropping log message.\n", 1, 0, 0);
185 SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond
);
188 static void cs_write_log_int(char *txt
)
192 cs_write_log(txt
, 1, 0, 0);
196 char *newtxt
= cs_strdup(txt
);
200 if(!cs_malloc(&log
, sizeof(struct s_log
)))
212 int32_t cs_open_logfiles(void)
215 if(logStarted
) { starttext
= "log switched"; }
216 else { starttext
= "started"; }
217 if(!fp
&& cfg
.logfile
) // log to file
219 if((fp
= fopen(cfg
.logfile
, "a+")) <= (FILE *)0)
222 fprintf(stderr
, "couldn't open logfile: %s (errno %d %s)\n", cfg
.logfile
, errno
, strerror(errno
));
227 memset(line
, '-', sizeof(line
));
228 line
[(sizeof(line
) / sizeof(char)) - 1] = '\0';
229 time_t walltime
= cs_time();
233 cs_ctime_r(&walltime
, buf
);
234 fprintf(fp
, "\n%s\n>> OSCam << cardserver %s at %s%s\n", line
, starttext
, buf
, line
);
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
);
243 return (fp
<= (FILE *)0);
246 #if defined(WEBIF) || defined(MODULE_MONITOR)
248 static uint64_t counter
= 0;
249 LLIST
*log_history
= NULL
;
252 This function allows to reinit the in-memory loghistory with a new size.
254 void cs_reinit_loghist(uint32_t size
)
256 if(cfg
.loghistorylines
!= size
)
258 cfg
.loghistorylines
= size
;
263 static struct timeb log_ts
;
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
)
268 struct s_client
*cl
= cur_client();
273 time_t walltime
= cs_walltime(&log_ts
);
274 localtime_r(&walltime
, <
);
276 tmp
= snprintf(txt
, txt_size
, "[LOG000]%04d/%02d/%02d %02d:%02d:%02d %08X %c ",
289 if(hdr_logcount_offset
!= NULL
)
291 // depends on snprintf(...) format
292 (*hdr_logcount_offset
) = 4;
295 if(hdr_date_offset
!= NULL
)
297 // depends on snprintf(...) format
298 (*hdr_date_offset
) = *hdr_logcount_offset
+ 4;
301 if(hdr_time_offset
!= NULL
)
303 // depends on snprintf(...) format
304 (*hdr_time_offset
) = *hdr_date_offset
+ 11;
307 if(hdr_info_offset
!= NULL
)
309 // depends on snprintf(...) format
310 (*hdr_info_offset
) = *hdr_time_offset
+ 9;
316 if(hdr_logcount_offset
!= NULL
)
318 (*hdr_logcount_offset
) = 0;
321 if(hdr_date_offset
!= NULL
)
323 (*hdr_date_offset
) = 0;
326 if(hdr_time_offset
!= NULL
)
328 (*hdr_time_offset
) = 0;
331 if(hdr_info_offset
!= NULL
)
333 (*hdr_info_offset
) = 0;
339 static void write_to_log(char *txt
, struct s_log
*log
, int8_t do_flush
)
344 (void)log
; // Prevent warning when WEBIF, MODULE_MONITOR and CS_ANTICASC are disabled
346 // anticascading messages go to their own log
347 if (!anticasc_logging(txt
+ log
->header_date_offset
))
351 syslog(LOG_INFO
, "%s", txt
+ log
->header_info_offset
);
354 if (cfg
.sysloghost
!= NULL
&& syslog_socket
!= -1)
356 char tmp
[128 + LOG_BUF_SIZE
];
357 static char hostname
[64];
358 static uint8_t have_hostname
= 0;
365 if(gethostname(hostname
, 64) != 0)
367 cs_strncpy(hostname
, "unknown", 64);
373 walltime
= cs_time();
374 localtime_r(&walltime
, <
);
376 if(strftime(timebuf
, 32, "%b %d %H:%M:%S", <
) == 0)
378 cs_strncpy(timebuf
, "unknown", 32);
381 snprintf(tmp
, sizeof(tmp
), "%s %s oscam[%u]: %s", timebuf
, hostname
, getpid(), txt
+ log
->header_info_offset
);
382 sendto(syslog_socket
, tmp
, cs_strlen(tmp
), 0, (struct sockaddr
*) &syslog_addr
, sizeof(syslog_addr
));
386 if (!cs_strncat(txt
, "\n", LOG_BUF_SIZE
)) {
389 cs_write_log(txt
, do_flush
, log
->header_date_offset
, log
->header_time_offset
);
391 #if defined(WEBIF) || defined(MODULE_MONITOR)
392 if(!exit_oscam
&& cfg
.loghistorylines
&& log_history
)
394 struct s_log_history
*hist
;
396 while((uint32_t)ll_count(log_history
) >= cfg
.loghistorylines
)
398 hist
= ll_remove_first(log_history
);
401 add_garbage(hist
->txt
);
407 if(cs_malloc(&hist
, sizeof(struct s_log_history
)))
409 int32_t target_len
= cs_strlen(log
->cl_text
) + cs_strlen(txt
+log
->header_date_offset
) + 1;
411 if(cs_malloc(&hist
->txt
, sizeof(char) * (target_len
+ 1)))
413 hist
->counter
= counter
++;
414 snprintf(hist
->txt
, target_len
+ 1, "%s\t%s", log
->cl_text
, txt
+ log
->header_date_offset
);
416 ll_append(log_history
, hist
);
426 #if defined(MODULE_MONITOR)
429 for(cl
= first_client
; cl
; cl
= cl
->next
)
431 if((cl
->typ
== 'm') && (cl
->monlvl
> 0) && cl
->log
) // this variable is only initialized for cl->typ = 'm'
435 if(log
->cl_typ
!= 'c' && log
->cl_typ
!= 'm')
438 if(log
->cl_usr
&& cl
->account
&& strcmp(log
->cl_usr
, cl
->account
->usr
))
442 if(log
->header_len
> 0)
444 snprintf(sbuf
, sizeof(sbuf
), "%03d", cl
->logcounter
);
445 cl
->logcounter
= (cl
->logcounter
+ 1) % 1000;
446 memcpy(txt
+ log
->header_logcount_offset
, sbuf
, 3);
447 monitor_send_idx(cl
, txt
);
451 char tmp_log
[8+LOG_BUF_SIZE
];
452 snprintf(tmp_log
, sizeof(tmp_log
), "[LOG%03d]%s", cl
->logcounter
, txt
);
453 cl
->logcounter
= (cl
->logcounter
+ 1) % 1000;
454 monitor_send_idx(cl
, tmp_log
);
461 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
)
463 #if !defined(WEBIF) && !defined(MODULE_MONITOR)
464 if(cfg
.disablelog
) { return; }
466 char *newtxt
= cs_strdup(txt
);
471 if(!cs_malloc(&log
, sizeof(struct s_log
)))
478 log
->header_len
= header_len
;
479 log
->header_logcount_offset
= hdr_logcount_offset
;
480 log
->header_date_offset
= hdr_date_offset
;
481 log
->header_time_offset
= hdr_time_offset
;
482 log
->header_info_offset
= hdr_info_offset
;
484 struct s_client
*cl
= cur_client();
489 log
->cl_text
= "undef";
500 log
->cl_text
= cl
->account
->usr
;
501 log
->cl_usr
= cl
->account
->usr
;
511 log
->cl_text
= cl
->reader
? cl
->reader
->label
: "";
515 log
->cl_text
= "server";
518 log
->cl_typ
= cl
->typ
;
521 if(exit_oscam
== 1 || cfg
.disablelog
) // Exit or log disabled. if disabled, just display on webif/monitor
523 char buf
[LOG_BUF_SIZE
];
524 cs_strncpy(buf
, log
->txt
, LOG_BUF_SIZE
);
525 write_to_log(buf
, log
, 1);
530 { log_list_add(log
); }
533 static pthread_mutex_t log_mutex
;
534 static char log_txt
[LOG_BUF_SIZE
];
535 static char dupl
[LOG_BUF_SIZE
/ 4];
536 static char last_log_txt
[LOG_BUF_SIZE
];
537 static struct timeb last_log_ts
;
538 static unsigned int last_log_duplicates
;
540 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
)
542 bool repeated_line
= strcmp(last_log_txt
, log_txt
+ hdr_len
) == 0;
543 if (last_log_duplicates
> 0)
545 if (!cs_valid_time(&last_log_ts
)) // Must be initialized once
546 last_log_ts
= log_ts
;
548 // Report duplicated lines when the new log line is different
549 // than the old or 60 seconds have passed.
550 int64_t gone
= comp_timeb(&log_ts
, &last_log_ts
);
552 if (!repeated_line
|| gone
>= 60 * 1000)
554 uint8_t dupl_hdr_logcount_offset
= 0, dupl_hdr_date_offset
= 0, dupl_hdr_time_offset
= 0, dupl_hdr_info_offset
= 0;
555 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
);
556 snprintf(dupl
+ dupl_header_len
- 1, sizeof(dupl
) - dupl_header_len
, " (-) -- Skipped %u duplicated log lines --", last_log_duplicates
);
557 write_to_log_int(dupl
, dupl_header_len
, dupl_hdr_logcount_offset
, dupl_hdr_date_offset
, dupl_hdr_time_offset
, dupl_hdr_info_offset
);
558 last_log_duplicates
= 0;
559 last_log_ts
= log_ts
;
565 memcpy(last_log_txt
, log_txt
+ hdr_len
, LOG_BUF_SIZE
- hdr_len
);
566 write_to_log_int(log_txt
, hdr_len
, hdr_logcount_offset
, hdr_date_offset
, hdr_time_offset
, hdr_info_offset
);
570 last_log_duplicates
++;
574 #define __init_log_prefix(fmt) \
575 uint8_t hdr_logcount_offset = 0, hdr_date_offset = 0, hdr_time_offset = 0, hdr_info_offset = 0; \
576 uint8_t hdr_len = get_log_header(log_txt, sizeof(log_txt), &hdr_logcount_offset, &hdr_date_offset, &hdr_time_offset, &hdr_info_offset); \
577 int32_t log_prefix_len = 0; \
581 snprintf(_lp, sizeof(_lp), "(%s)", log_prefix); \
582 log_prefix_len = snprintf(log_txt + hdr_len, sizeof(log_txt) - hdr_len, fmt, _lp); \
589 va_start(params, fmt); \
590 __init_log_prefix("%10s "); \
591 vsnprintf(log_txt + hdr_len + log_prefix_len, sizeof(log_txt) - (hdr_len + log_prefix_len), fmt, params); \
593 if (cfg.logduplicatelines) \
595 memcpy(last_log_txt, log_txt + hdr_len, LOG_BUF_SIZE - hdr_len); \
596 write_to_log_int(log_txt, hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset); \
598 __cs_log_check_duplicates(hdr_len, hdr_logcount_offset, hdr_date_offset, hdr_time_offset, hdr_info_offset); \
602 void cs_log_txt(const char *log_prefix
, const char *fmt
, ...)
607 SAFE_MUTEX_LOCK_NOLOG(&log_mutex
);
609 SAFE_MUTEX_UNLOCK_NOLOG(&log_mutex
);
612 void cs_log_hex(const char *log_prefix
, const uint8_t *buf
, int32_t n
, const char *fmt
, ...)
617 SAFE_MUTEX_LOCK_NOLOG(&log_mutex
);
622 __init_log_prefix("%10s ");
623 for(i
= 0; i
< n
; i
+= 16)
625 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
));
626 write_to_log_int(log_txt
, hdr_len
, hdr_logcount_offset
, hdr_date_offset
, hdr_time_offset
, hdr_info_offset
);
629 SAFE_MUTEX_UNLOCK_NOLOG(&log_mutex
);
632 static void cs_close_log(void)
642 int32_t cs_init_statistics(void)
644 if((!fps
) && (cfg
.usrfile
!= NULL
))
646 if((fps
= fopen(cfg
.usrfile
, "a+")) <= (FILE *)0)
649 cs_log("couldn't open statistics file: %s", cfg
.usrfile
);
652 return (fps
<= (FILE *)0);
655 void cs_statistics(struct s_client
*client
)
657 if(!cfg
.disableuserfile
)
660 char buf
[LOG_BUF_SIZE
];
664 time_t walltime
= cs_time();
665 localtime_r(&walltime
, <
);
666 if(client
->cwfound
+ client
->cwnot
> 0)
668 cwps
= client
->last
- client
->login
;
669 cwps
/= client
->cwfound
+ client
->cwnot
;
674 char channame
[CS_SERVICENAME_SIZE
];
675 get_servicename(client
, client
->last_srvid
, client
->last_provid
, client
->last_caid
, channame
, sizeof(channame
));
678 if((client
->last_caid
== NO_CAID_VALUE
) && (client
->last_srvid
== NO_SRVID_VALUE
))
679 { lsec
= client
->last
- client
->login
; } //client leave calc total duration
681 { lsec
= client
->last
- client
->lastswitch
; }
683 int32_t secs
= 0, fullmins
= 0, mins
= 0, fullhours
= 0;
685 if((lsec
> 0) && (lsec
< 1000000))
690 fullmins
= lsec
/ 60;
691 mins
= fullmins
% 60;
694 fullhours
= fullmins
/ 60;
699 /* statistics entry start with 's' to filter it out on other end of pipe
700 * so we can use the same Pipe as Log
702 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",
703 lt
.tm_mday
, lt
.tm_mon
+ 1, lt
.tm_year
% 100,
704 lt
.tm_hour
, lt
.tm_min
, lt
.tm_sec
, cwps
,
705 client
->account
->usr
,
706 cs_inet_ntoa(client
->ip
),
716 fullhours
, mins
, secs
,
717 get_module(client
)->desc
,
723 cs_write_log_int(buf
);
727 void log_list_thread(void)
729 char buf
[LOG_BUF_SIZE
];
731 set_thread_name(__func__
);
735 LL_ITER it
= ll_iter_create(log_list
);
737 while((log
= ll_iter_next_remove(&it
)))
739 int8_t do_flush
= ll_count(log_list
) == 0; // flush on writing last element
741 cs_strncpy(buf
, log
->txt
, LOG_BUF_SIZE
);
743 { cs_write_log(buf
, do_flush
, log
->header_date_offset
, log
->header_time_offset
); }
745 { write_to_log(buf
, log
, do_flush
); }
749 if(!log_list_queued
) // The list is empty, sleep until new data comes in and we are woken up
750 sleepms_on_cond(__func__
, &log_thread_sleep_cond_mutex
, &log_thread_sleep_cond
, 60 * 1000);
753 ll_destroy(&log_list
);
756 static void init_syslog_socket(void)
758 if(cfg
.sysloghost
!= NULL
&& syslog_socket
== -1)
762 if ((syslog_socket
= socket(DEFAULT_AF
, SOCK_DGRAM
, IPPROTO_UDP
)) == -1)
764 perror("Socket create error!");
767 memset((char *) &syslog_addr
, 0, sizeof(syslog_addr
));
768 SIN_GET_FAMILY(syslog_addr
) = DEFAULT_AF
;
769 SIN_GET_PORT(syslog_addr
) = htons(cfg
.syslogport
);
770 cs_resolve(cfg
.sysloghost
, &in_addr
, NULL
, NULL
);
771 SIN_GET_ADDR(syslog_addr
) = in_addr
;
775 int32_t cs_init_log(void)
779 init_syslog_socket();
780 SAFE_MUTEX_INIT_NOLOG(&log_mutex
, NULL
);
782 cs_pthread_cond_init_nolog(__func__
, &log_thread_sleep_cond_mutex
, &log_thread_sleep_cond
);
784 #if defined(WEBIF) || defined(MODULE_MONITOR)
785 log_history
= ll_create("log history");
788 log_list
= ll_create(LOG_LIST
);
790 int32_t ret
= start_thread_nolog("logging", (void *)&log_list_thread
, NULL
, &log_thread
, 0, 1);
800 if(!cfg
.disablelog
) { rc
= cs_open_logfiles(); }
803 if(cfg
.initial_debuglevel
> 0)
805 cs_dblevel
= cfg
.initial_debuglevel
;
806 cs_log("debug_level=%d", cs_dblevel
);
812 void cs_disable_log(int8_t disabled
)
814 if(cfg
.disablelog
!= disabled
)
816 if(disabled
&& logStarted
)
818 cs_log("Stopping log...");
822 cfg
.disablelog
= disabled
;
827 if(syslog_socket
!= -1)
829 close(syslog_socket
);
839 init_syslog_socket();
847 if(syslog_socket
!= -1)
849 close(syslog_socket
);
855 SAFE_COND_SIGNAL_NOLOG(&log_thread_sleep_cond
);
856 SAFE_THREAD_JOIN_NOLOG(log_thread
, NULL
);