1 /*
2 ** Logging framework.
3 **
4 ** This program is distributed under the GNU General Public License, version 2.
5 ** A copy of this license is included with this source.
6 */
7
8 #ifdef HAVE_CONFIG_H
9 #include <config.h>
10 #endif
11 #ifndef _POSIX_C_SOURCE
12 #define _POSIX_C_SOURCE 200809L
13 #endif
14 #include <stdio.h>
15 #include <stdlib.h>
16 #include <stdarg.h>
17 #include <string.h>
18 #include <time.h>
19 #ifdef HAVE_SYS_TYPES_H
20 #include <sys/types.h>
21 #endif
22 #ifdef HAVE_SYS_STAT_H
23 #include <sys/stat.h>
24 #endif
25 #ifdef HAVE_UNISTD_H
26 #include <unistd.h>
27 #endif
28
29
30 #include "log.h"
31
32 #define LOG_MAXLOGS logs_allocated
33 #define LOG_MAXLINELEN 1024
34
35
36 static void *_logger_mutex;
37 static int _initialized = 0;
38
39 static mx_create_func log_mutex_alloc;
40 static mx_lock_func log_mutex_lock;
41 static log_commit_callback log_callback;
42
43
44 typedef struct _log_entry_t
45 {
46 struct _log_entry_t *next;
47 char *line;
48 unsigned int len;
49 } log_entry_t;
50
51
52 typedef struct log_tag
53 {
54 int in_use;
55
56 unsigned level;
57
58 char *filename;
59 FILE *logfile;
60 off_t size;
61 off_t trigger_level;
62 time_t reopen_at;
63 unsigned int duration;
64 short archive_timestamp;
65 time_t recheck_time;
66
67 unsigned long buffer_bytes;
68 unsigned int entries;
69 unsigned int keep_entries;
70 log_entry_t *written_entry;
71 log_entry_t *log_head;
72 log_entry_t *log_tail;
73
74 char *buffer;
75 } log_t;
76
77 int logs_allocated;
78 static log_t *loglist;
79
80 static int _get_log_id(void);
81 static void _release_log_id(int log_id);
82 static void _lock_logger(void);
83 static void _unlock_logger(void);
84 static int do_log_run (int log_id);
85
86
_log_open(int id,time_t now)87 static int _log_open (int id, time_t now)
88 {
89 if (loglist [id] . in_use == 0)
90 return 0;
91
92 /* check for cases where an open of the logfile is wanted */
93 if (loglist [id] . logfile == NULL ||
94 (loglist [id] . duration && loglist [id] . reopen_at <= now) ||
95 (loglist [id] . trigger_level && loglist [id] . size > loglist [id] . trigger_level))
96 {
97 if (loglist [id] . filename) /* only re-open files where we have a name */
98 {
99 FILE *f = NULL;
100 struct stat st;
101 int exists = 0, archive = 1;
102
103 if (stat (loglist [id] . filename, &st) == 0)
104 {
105 exists = 1;
106 if ((loglist [id] . trigger_level && loglist [id] . size > loglist [id] . trigger_level) &&
107 st.st_size < loglist [id] . trigger_level)
108 { // log changed from under us, but less than trigger size, better reopen this and not archive for now.
109 archive = 0;
110 }
111 }
112 if (loglist [id].logfile && loglist [id].logfile != stderr)
113 {
114 char new_name [4096];
115 fclose (loglist [id] . logfile);
116 loglist [id] . logfile = NULL;
117 if (archive)
118 {
119 if (loglist[id].archive_timestamp)
120 {
121 char timestamp [128];
122
123 strftime (timestamp, sizeof (timestamp), "%Y%m%d_%H%M%S", localtime (&now));
124 snprintf (new_name, sizeof(new_name), "%s.%s", loglist[id].filename, timestamp);
125 }
126 else {
127 snprintf (new_name, sizeof(new_name), "%s.old", loglist [id] . filename);
128 }
129 if (exists)
130 {
131 #ifdef _WIN32
132 remove (new_name);
133 #endif
134 rename (loglist [id] . filename, new_name);
135 }
136 }
137 }
138 f = fopen (loglist [id] . filename, "a");
139 if (f == NULL)
140 {
141 if (loglist [id] . logfile != stderr)
142 {
143 loglist [id] . logfile = stderr;
144 do_log_run (id);
145 }
146 return 0;
147 }
148 loglist [id].logfile = f;
149 setvbuf (loglist [id] . logfile, NULL, IO_BUFFER_TYPE, 0);
150 if (stat (loglist [id] . filename, &st) < 0)
151 loglist [id] . size = 0;
152 else
153 loglist [id] . size = st.st_size;
154 if (loglist [id] . duration)
155 loglist [id] . reopen_at = now + loglist [id] . duration;
156 loglist [id].recheck_time = now + 10;
157 }
158 else
159 loglist [id] . size = 0;
160 }
161 return 1;
162 }
163
log_init(log_t * log)164 static void log_init (log_t *log)
165 {
166 log->in_use = 0;
167 log->level = 2;
168 log->size = 0;
169 log->trigger_level = 50*1024*1024;
170 log->duration = 0;
171 log->filename = NULL;
172 log->logfile = NULL;
173 log->buffer = NULL;
174 log->buffer_bytes = 0;
175 log->entries = 0;
176 log->keep_entries = 5;
177 log->written_entry = NULL;
178 log->log_head = NULL;
179 log->log_tail = NULL;
180 }
181
log_initialize_lib(mx_create_func mxc,mx_lock_func mxl)182 void log_initialize_lib (mx_create_func mxc, mx_lock_func mxl)
183 {
184 if (_initialized) return;
185 logs_allocated = 0;
186 loglist = NULL;
187 log_mutex_alloc = mxc ? mxc : NULL;
188 log_mutex_lock = mxl ? mxl : NULL;
189
190 if (log_mutex_alloc)
191 log_mutex_alloc (&_logger_mutex, 1);
192 log_callback = NULL;
193 _initialized = 1;
194 }
195
196
log_initialize(void)197 void log_initialize(void)
198 {
199 if (_initialized) return;
200
201 logs_allocated = 0;
202 loglist = NULL;
203 /* initialize mutexes */
204
205 _initialized = 1;
206 log_callback = NULL;
207 }
208
log_open_file(FILE * file)209 int log_open_file(FILE *file)
210 {
211 int log_id;
212
213 if(file == NULL) return LOG_EINSANE;
214
215 log_id = _get_log_id();
216 if (log_id < 0) return LOG_ENOMORELOGS;
217
218 loglist[log_id].logfile = file;
219 loglist[log_id].filename = NULL;
220 loglist[log_id].size = 0;
221 loglist[log_id].reopen_at = 0;
222 loglist[log_id].archive_timestamp = 0;
223
224 return log_id;
225 }
226
227
log_open(const char * filename)228 int log_open(const char *filename)
229 {
230 int id;
231
232 if (filename == NULL) return LOG_EINSANE;
233 if (strcmp(filename, "") == 0) return LOG_EINSANE;
234
235 id = _get_log_id();
236
237 if (id >= 0)
238 {
239 _lock_logger();
240 free (loglist [id] . filename);
241 loglist [id] . filename = strdup (filename);
242 loglist [id].entries = 0;
243 loglist [id].log_head = NULL;
244 loglist [id].log_tail = NULL;
245 loglist [id].logfile = NULL;
246 loglist [id].size = 0;
247 loglist [id].reopen_at = 0;
248 loglist [id].archive_timestamp = 0;
249 _unlock_logger();
250 }
251
252 return id;
253 }
254
255
256 /* set the trigger level to trigger, represented in bytes */
log_set_trigger(int id,unsigned long trigger)257 void log_set_trigger(int id, unsigned long trigger)
258 {
259 _lock_logger();
260 if (id >= 0 && id < LOG_MAXLOGS && loglist [id] . in_use)
261 {
262 if (trigger < 100000)
263 trigger = 100000;
264 loglist [id] . trigger_level = trigger;
265 }
266 _unlock_logger();
267 }
268
269
log_set_reopen_after(int id,unsigned int trigger)270 void log_set_reopen_after (int id, unsigned int trigger)
271 {
272 _lock_logger();
273 if (id >= 0 && id < LOG_MAXLOGS && loglist [id] . in_use)
274 {
275 loglist [id] . duration = trigger;
276 loglist [id] . reopen_at = trigger ? time (NULL) + trigger : 0;
277 }
278 _unlock_logger();
279 }
280
281
log_set_filename(int id,const char * filename)282 int log_set_filename(int id, const char *filename)
283 {
284 if (id < 0 || id >= LOG_MAXLOGS)
285 return LOG_EINSANE;
286 /* NULL filename is ok, empty filename is not. */
287 if (filename && !strcmp(filename, ""))
288 return LOG_EINSANE;
289 _lock_logger();
290 if (loglist [id] . in_use)
291 {
292 if (loglist [id] . filename)
293 free (loglist [id] . filename);
294 if (filename)
295 loglist [id] . filename = strdup (filename);
296 else
297 loglist [id] . filename = NULL;
298 }
299 _unlock_logger();
300 return id;
301 }
302
log_set_archive_timestamp(int id,int value)303 int log_set_archive_timestamp(int id, int value)
304 {
305 if (id < 0 || id >= LOG_MAXLOGS)
306 return LOG_EINSANE;
307 _lock_logger();
308 loglist[id].archive_timestamp = value;
309 _unlock_logger();
310 return id;
311 }
312
313
log_open_with_buffer(const char * filename,int size)314 int log_open_with_buffer(const char *filename, int size)
315 {
316 /* not implemented */
317 return LOG_ENOTIMPL;
318 }
319
320
log_set_lines_kept(int log_id,unsigned int count)321 void log_set_lines_kept (int log_id, unsigned int count)
322 {
323 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
324 if (loglist[log_id].in_use == 0) return;
325 if (count > 1000000) return;
326
327 _lock_logger ();
328 loglist[log_id].keep_entries = count;
329 _unlock_logger ();
330 }
331
332
log_set_level(int log_id,unsigned level)333 void log_set_level(int log_id, unsigned level)
334 {
335 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
336 _lock_logger();
337 if (loglist[log_id].in_use)
338 loglist[log_id].level = level;
339 _unlock_logger();
340 }
341
log_flush(int log_id)342 void log_flush(int log_id)
343 {
344 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
345 if (loglist[log_id].in_use == 0) return;
346
347 _lock_logger();
348 if (loglist[log_id].logfile)
349 fflush(loglist[log_id].logfile);
350 _unlock_logger();
351 }
352
log_reopen(int log_id)353 void log_reopen(int log_id)
354 {
355 if (log_id < 0 && log_id >= LOG_MAXLOGS)
356 return;
357 _lock_logger();
358 do
359 {
360 if (loglist [log_id] . filename == NULL || loglist [log_id] . logfile == NULL)
361 break;
362 if (loglist [log_id]. archive_timestamp < 0)
363 {
364 struct stat st;
365 fflush (loglist [log_id] . logfile);
366 if (stat (loglist [log_id] . filename, &st) == 0 && st.st_size == loglist [log_id].size)
367 break;
368 // a missing or different sized log indicates an external move so trigger a reopen
369 }
370 loglist [log_id].size = loglist [log_id].trigger_level + 1;
371 } while (0);
372 _unlock_logger();
373 }
374
375
376
_log_close_internal(int log_id)377 static void _log_close_internal (int log_id)
378 {
379 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
380
381 int loop = 0;
382 while (++loop < 10 && do_log_run (log_id) > 0)
383 ;
384 loglist[log_id].level = 2;
385 free (loglist[log_id].filename);
386 loglist[log_id].filename = NULL;
387 if (loglist[log_id].buffer) free(loglist[log_id].buffer);
388
389 if (loglist [log_id] . logfile)
390 {
391 fclose (loglist [log_id] . logfile);
392 loglist [log_id] . logfile = NULL;
393 }
394 while (loglist [log_id].log_head)
395 {
396 log_entry_t *to_go = loglist [log_id].log_head;
397 loglist [log_id].log_head = to_go->next;
398 loglist [log_id].buffer_bytes -= to_go->len;
399 free (to_go->line);
400 free (to_go);
401 loglist [log_id].entries--;
402 }
403 loglist [log_id].written_entry = NULL;
404 loglist [log_id].entries = 0;
405 loglist [log_id].in_use = 0;
406 }
407
408
log_close(int log_id)409 void log_close(int log_id)
410 {
411 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
412
413 _lock_logger();
414
415 if (loglist[log_id].in_use != 1)
416 {
417 if (loglist[log_id].in_use == 3)
418 loglist[log_id].in_use = 1;
419 _unlock_logger();
420 return;
421 }
422 _log_close_internal (log_id);
423 _unlock_logger();
424 }
425
426
log_shutdown(void)427 void log_shutdown(void)
428 {
429 int log_id;
430 log_commit_entries ();
431 for (log_id = 0; log_id < logs_allocated ; log_id++)
432 log_close (log_id);
433 logs_allocated = 0;
434 free (loglist);
435 /* destroy mutexes */
436 if (log_mutex_alloc)
437 log_mutex_alloc (&_logger_mutex, 0);
438
439 _initialized = 0;
440 }
441
log_entry_pop(int log_id)442 static log_entry_t *log_entry_pop (int log_id)
443 {
444 log_entry_t *to_go = loglist [log_id].log_head;
445
446 if (to_go == NULL || loglist [log_id].written_entry == NULL || loglist [log_id].written_entry == to_go)
447 return NULL;
448 loglist [log_id].log_head = to_go->next;
449 loglist [log_id].buffer_bytes -= to_go->len;
450 loglist [log_id].entries--;
451
452 if (to_go == loglist [log_id].log_tail)
453 loglist [log_id].log_tail = NULL;
454
455 if (to_go == loglist [log_id].written_entry)
456 loglist [log_id].written_entry = NULL;
457
458 return to_go;
459 }
460
461 // flush out any waiting log entries
462 //
do_log_run(int log_id)463 static int do_log_run (int log_id)
464 {
465 log_entry_t *next;
466 int loop = 0;
467 time_t now;
468
469 loglist [log_id].in_use = 3;
470 time (&now);
471 if (loglist [log_id].written_entry == NULL)
472 next = loglist [log_id].log_head;
473 else
474 next = loglist [log_id].written_entry->next;
475
476 if (next && loglist[log_id].logfile && loglist [log_id] .filename && loglist [log_id].recheck_time <= now)
477 {
478 struct stat st;
479 loglist [log_id].recheck_time = now + 6;
480 if (fstat (fileno(loglist[log_id].logfile), &st) < 0)
481 {
482 loglist [log_id].size = loglist [log_id].trigger_level+1;
483 // fprintf (stderr, "recheck size of %s, failed\n", loglist [log_id] .filename);
484 }
485 else
486 {
487 // fprintf (stderr, "recheck size of %s, %s\n", loglist [log_id] .filename, (loglist [log_id].size == st.st_size) ? "ok" :"different");
488 loglist [log_id] . size = st.st_size;
489 }
490 }
491 // fprintf (stderr, "in log run, id %d\n", log_id);
492 while (next && ++loop < 300)
493 {
494 if (_log_open (log_id, now) == 0)
495 break;
496
497 loglist [log_id].written_entry = next;
498 _unlock_logger ();
499
500 // fprintf (stderr, "in log run, line is %s\n", next->line);
501 if (fprintf (loglist [log_id].logfile, "%s\n", next->line) >= 0)
502 loglist [log_id].size += (next->len + 1);
503
504 _lock_logger ();
505 next = next->next;
506 }
507 if (loglist [log_id].in_use == 3)
508 loglist [log_id].in_use = 1; // normal route
509 else
510 _log_close_internal (log_id); // log_close could of triggered
511 return loop;
512 }
513
log_commit_entries()514 void log_commit_entries ()
515 {
516 int count = 0, c = 0, log_id;
517
518 //fprintf (stderr, "in log commit\n");
519 _lock_logger ();
520 for (log_id = 0; log_id < logs_allocated ; log_id++)
521 {
522 do
523 {
524 if (loglist [log_id].in_use)
525 c = do_log_run (log_id);
526 if (c == 0) break; // skip to next log
527 } while ((count += c) < 1000);
528 }
529 _unlock_logger ();
530 }
531
532
533 // set callback routine for whenever a log message is performed
534 //
log_set_commit_callback(log_commit_callback f)535 void log_set_commit_callback (log_commit_callback f)
536 {
537 log_callback = f;
538 }
539
540
541 // purge log entries back to least 1 on the specified log, assumes lock in use
542 //
do_purge(int log_id)543 static void do_purge (int log_id)
544 {
545 int last = loglist [log_id].keep_entries;
546
547 //fprintf (stderr, "in log purge, id %d, last %d, entries %d\n", log_id, last, loglist [log_id].entries);
548 while (loglist [log_id].entries > last)
549 {
550 log_entry_t *to_go = log_entry_pop (log_id);
551
552 if (to_go)
553 {
554 //fprintf (stderr, " log purge (%d), %s\n", loglist [log_id].entries, to_go->line);
555 free (to_go->line);
556 free (to_go);
557 continue;
558 }
559 break;
560 }
561 }
562
563
create_log_entry(int log_id,const char * line)564 static int create_log_entry (int log_id, const char *line)
565 {
566 log_entry_t *entry;
567 int len;
568
569 entry = calloc (1, sizeof (log_entry_t));
570 len = entry->len = strlen (line);
571 entry->line = malloc (entry->len+1);
572 snprintf (entry->line, entry->len+1, "%s", line);
573 loglist [log_id].buffer_bytes += entry->len;
574
575 if (loglist [log_id].log_tail)
576 loglist [log_id].log_tail->next = entry;
577 else
578 loglist [log_id].log_head = entry;
579
580 loglist [log_id].log_tail = entry;
581 loglist [log_id].entries++;
582 if (log_callback)
583 log_callback (log_id);
584 else
585 do_log_run (log_id);
586 do_purge (log_id);
587 return len;
588 }
589
590
log_contents(int log_id,char ** _contents,unsigned int * _len)591 int log_contents (int log_id, char **_contents, unsigned int *_len)
592 {
593 int remain;
594 log_entry_t *entry;
595 char *ptr;
596
597 if (log_id < 0) return -1;
598 if (log_id >= LOG_MAXLOGS) return -1; /* Bad log number */
599
600 if (_contents == NULL)
601 {
602 _lock_logger (); // normal initial route
603 if (loglist [log_id].in_use == 0)
604 {
605 _unlock_logger ();
606 return -1;
607 }
608 *_len = loglist [log_id].buffer_bytes + loglist [log_id].entries; // add space for newlines
609 return 1;
610 }
611 remain = *_len;
612
613 entry = loglist [log_id].log_head;
614 ptr = *_contents;
615 *ptr = '\0';
616 while (entry && remain)
617 {
618 int len = snprintf (ptr, remain, "%s\n", entry->line);
619 if (len > 0)
620 {
621 ptr += len;
622 remain -= len;
623 }
624 entry = entry->next;
625 }
626 _unlock_logger ();
627 if (remain)
628 *_len -= remain;
629 return 0;
630 }
631
632
log_write(int log_id,unsigned priority,const char * cat,const char * func,const char * fmt,...)633 void log_write(int log_id, unsigned priority, const char *cat, const char *func,
634 const char *fmt, ...)
635 {
636 static char *prior[] = { "EROR", "WARN", "INFO", "DBUG" };
637 int datelen;
638 time_t now;
639 struct tm thetime;
640 char line[LOG_MAXLINELEN];
641 va_list ap;
642
643 if (log_id < 0 || log_id >= LOG_MAXLOGS) return; /* Bad log number */
644 if (loglist[log_id].level < priority) return;
645 if (priority > sizeof(prior)/sizeof(prior[0])) return; /* Bad priority */
646
647 va_start(ap, fmt);
648
649 now = time(NULL);
650
651 datelen = strftime (line, sizeof (line), "[%Y-%m-%d %H:%M:%S]", localtime_r(&now, &thetime));
652
653 datelen += snprintf (line+datelen, sizeof line-datelen, " %s %s%s ", prior [priority-1], cat, func);
654 vsnprintf (line+datelen, sizeof line-datelen, fmt, ap);
655
656 _lock_logger();
657 create_log_entry (log_id, line);
658 _unlock_logger();
659
660 va_end(ap);
661 }
662
log_write_direct(int log_id,const char * fmt,...)663 void log_write_direct(int log_id, const char *fmt, ...)
664 {
665 va_list ap;
666 char line[LOG_MAXLINELEN];
667
668 if (log_id < 0 || log_id >= LOG_MAXLOGS) return;
669
670 va_start(ap, fmt);
671
672 _lock_logger();
673 vsnprintf(line, LOG_MAXLINELEN, fmt, ap);
674 create_log_entry (log_id, line);
675 _unlock_logger();
676
677 va_end(ap);
678 }
679
_get_log_id(void)680 static int _get_log_id(void)
681 {
682 int i;
683 int id = -1;
684
685 /* lock mutex */
686 _lock_logger();
687
688 for (i = 0; i < logs_allocated; i++)
689 if (loglist[i].in_use == 0) {
690 loglist[i].in_use = 1;
691 id = i;
692 break;
693 }
694 if (id == -1)
695 {
696 int new_count = logs_allocated + 20;
697 log_t *new_list = realloc (loglist, new_count * sizeof (log_t));
698 if (new_list)
699 {
700 for (i = logs_allocated; i < new_count; i++)
701 log_init (&new_list[i]);
702 loglist = new_list;
703 id = logs_allocated;
704 loglist[id].in_use = 1;
705 logs_allocated = new_count;
706 }
707 }
708
709 /* unlock mutex */
710 _unlock_logger();
711
712 return id;
713 }
714
_release_log_id(int log_id)715 static void _release_log_id(int log_id)
716 {
717 /* lock mutex */
718 _lock_logger();
719
720 loglist[log_id].in_use = 0;
721
722 /* unlock mutex */
723 _unlock_logger();
724 }
725
_lock_logger(void)726 static void _lock_logger(void)
727 {
728 if (log_mutex_lock)
729 log_mutex_lock (&_logger_mutex, 1);
730 }
731
_unlock_logger(void)732 static void _unlock_logger(void)
733 {
734 if (log_mutex_lock)
735 log_mutex_lock (&_logger_mutex, 0);
736 }
737
738
739
740
741