1 /* ====================================================================
2  * The Kannel Software License, Version 1.0
3  *
4  * Copyright (c) 2001-2014 Kannel Group
5  * Copyright (c) 1998-2001 WapIT Ltd.
6  * All rights reserved.
7  *
8  * Redistribution and use in source and binary forms, with or without
9  * modification, are permitted provided that the following conditions
10  * are met:
11  *
12  * 1. Redistributions of source code must retain the above copyright
13  *    notice, this list of conditions and the following disclaimer.
14  *
15  * 2. Redistributions in binary form must reproduce the above copyright
16  *    notice, this list of conditions and the following disclaimer in
17  *    the documentation and/or other materials provided with the
18  *    distribution.
19  *
20  * 3. The end-user documentation included with the redistribution,
21  *    if any, must include the following acknowledgment:
22  *       "This product includes software developed by the
23  *        Kannel Group (http://www.kannel.org/)."
24  *    Alternately, this acknowledgment may appear in the software itself,
25  *    if and wherever such third-party acknowledgments normally appear.
26  *
27  * 4. The names "Kannel" and "Kannel Group" must not be used to
28  *    endorse or promote products derived from this software without
29  *    prior written permission. For written permission, please
30  *    contact org@kannel.org.
31  *
32  * 5. Products derived from this software may not be called "Kannel",
33  *    nor may "Kannel" appear in their name, without prior written
34  *    permission of the Kannel Group.
35  *
36  * THIS SOFTWARE IS PROVIDED ``AS IS'' AND ANY EXPRESSED OR IMPLIED
37  * WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES
38  * OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE
39  * DISCLAIMED.  IN NO EVENT SHALL THE KANNEL GROUP OR ITS CONTRIBUTORS
40  * BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY,
41  * OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT
42  * OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR
43  * BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY,
44  * WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE
45  * OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE,
46  * EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
47  * ====================================================================
48  *
49  * This software consists of voluntary contributions made by many
50  * individuals on behalf of the Kannel Group.  For more information on
51  * the Kannel Group, please see <http://www.kannel.org/>.
52  *
53  * Portions of this software are based upon software originally written at
54  * WapIT Ltd., Helsinki, Finland for the Kannel project.
55  */
56 
57 /*
58  * log.c - implement logging functions
59  */
60 
61 #include "gwlib.h"
62 #include <limits.h>
63 #include <stdio.h>
64 #include <stdlib.h>
65 #include <errno.h>
66 #include <time.h>
67 #include <stdarg.h>
68 #include <string.h>
69 #include <ctype.h>
70 
71 #ifdef HAVE_EXECINFO_H
72 #include <execinfo.h>
73 #endif
74 
75 #if HAVE_SYSLOG_H
76 #define	SYSLOG_NAMES
77 #include <syslog.h>
78 
79 /*
80  * Decode the syslog name to its int value
81  */
decode(char * name)82 static int decode(char *name)
83 {
84     register CODE *c;
85     CODE *facilities = facilitynames;
86 
87     if (isdigit(*name)) {
88         return (atoi(name));
89     }
90     for (c = facilities; c->c_name; c++) {
91         if (!strcasecmp(name, c->c_name)) {
92             return (c->c_val);
93         }
94     }
95     return LOG_DAEMON;
96 }
97 
98 #else
99 
100 /*
101  * If we don't have syslog.h, then we'll use the following dummy definitions
102  * to avoid writing #if HAVE_SYSLOG_H everywhere.
103  */
104 
105 enum {
106     LOG_PID, LOG_DAEMON, LOG_DEBUG, LOG_INFO, LOG_WARNING, LOG_ERR, LOG_ALERT
107 };
108 
decode(char * name)109 static int decode(char *name)
110 {
111     return LOG_DAEMON;
112 }
113 
openlog(const char * ident,int option,int facility)114 static void openlog(const char *ident, int option, int facility)
115 {
116 }
117 
syslog(int translog,const char * msg,...)118 static void syslog(int translog, const char *msg, ...)
119 {
120 }
121 
closelog(void)122 static void closelog(void)
123 {
124 }
125 #endif
126 
127 
128 /*
129  * List of currently open log files.
130  */
131 #define MAX_LOGFILES 128
132 static struct {
133     FILE *file;
134     int minimum_output_level;
135     char filename[FILENAME_MAX + 1]; /* to allow re-open */
136     enum excl_state exclusive;
137 } logfiles[MAX_LOGFILES];
138 static int num_logfiles = 0;
139 
140 
141 /*
142  * Mapping array between thread id and logfiles[] index.
143  * This is used for smsc specific logging.
144  */
145 #define THREADTABLE_SIZE 1024
146 static unsigned int thread_to[(long)THREADTABLE_SIZE];
147 
148 
149 /*
150  * Ensure we use the real threadtable slot number to map the thread id
151  * instead of the thread id reported by gwthread_self()
152  */
153 #define thread_slot() \
154     (gwthread_self() % THREADTABLE_SIZE)
155 
156 
157 /*
158  * List of places that should be logged at debug-level.
159  */
160 #define MAX_LOGGABLE_PLACES (10*1000)
161 static char *loggable_places[MAX_LOGGABLE_PLACES];
162 static int num_places = 0;
163 
164 
165 /*
166  * Reopen/rotate locking things.
167  */
168 static RWLock rwlock;
169 
170 /*
171  * Syslog support.
172  */
173 static int sysloglevel;
174 static int syslogfacility = LOG_DAEMON;
175 static int dosyslog = 0;
176 
177 /*
178  * Make sure stderr is included in the list.
179  */
add_stderr(void)180 static void add_stderr(void)
181 {
182     int i;
183 
184     for (i = 0; i < num_logfiles; ++i)
185 	if (logfiles[i].file == stderr)
186 	    return;
187     logfiles[num_logfiles].file = stderr;
188     logfiles[num_logfiles].minimum_output_level = GW_DEBUG;
189     logfiles[num_logfiles].exclusive = GW_NON_EXCL;
190     ++num_logfiles;
191 }
192 
193 
log_init(void)194 void log_init(void)
195 {
196     unsigned long i;
197 
198     /* Initialize rwlock */
199     gw_rwlock_init_static(&rwlock);
200 
201     /* default all possible thread to logging index 0, stderr */
202     for (i = 0; i < THREADTABLE_SIZE; i++) {
203         thread_to[i] = 0;
204     }
205 
206     add_stderr();
207 }
208 
log_shutdown(void)209 void log_shutdown(void)
210 {
211     log_close_all();
212     /* destroy rwlock */
213     gw_rwlock_destroy(&rwlock);
214 }
215 
216 
log_set_output_level(enum output_level level)217 void log_set_output_level(enum output_level level)
218 {
219     int i;
220 
221     for (i = 0; i < num_logfiles; ++i) {
222         if (logfiles[i].file == stderr) {
223             logfiles[i].minimum_output_level = level;
224             break;
225         }
226     }
227 }
228 
log_set_log_level(enum output_level level)229 void log_set_log_level(enum output_level level)
230 {
231     int i;
232 
233     /* change everything but stderr */
234     for (i = 0; i < num_logfiles; ++i) {
235         if (logfiles[i].file != stderr) {
236             logfiles[i].minimum_output_level = level;
237             info(0, "Changed logfile `%s' to level `%d'.", logfiles[i].filename, level);
238         }
239     }
240 }
241 
log_set_syslog_facility(char * facility)242 void log_set_syslog_facility(char *facility)
243 {
244     if (facility != NULL)
245         syslogfacility = decode(facility);
246 }
247 
log_set_syslog(const char * ident,int syslog_level)248 void log_set_syslog(const char *ident, int syslog_level)
249 {
250     if (ident == NULL)
251         dosyslog = 0;
252     else {
253         dosyslog = 1;
254         sysloglevel = syslog_level;
255         openlog(ident, LOG_PID, syslogfacility);
256         debug("gwlib.log", 0, "Syslog logging enabled.");
257     }
258 }
259 
260 
log_reopen(void)261 void log_reopen(void)
262 {
263     int i, j, found;
264 
265     /*
266      * Writer lock.
267      */
268     gw_rwlock_wrlock(&rwlock);
269 
270     for (i = 0; i < num_logfiles; ++i) {
271         if (logfiles[i].file != stderr) {
272             found = 0;
273 
274             /*
275              * Reverse seek for allready reopened logfile.
276              * If we find a previous file descriptor for the same file
277              * name, then don't reopen that duplicate, but assign the
278              * file pointer to it.
279              */
280             for (j = i-1; j >= 0 && found == 0; j--) {
281                 if (strcmp(logfiles[i].filename, logfiles[j].filename) == 0) {
282                     logfiles[i].file = logfiles[j].file;
283                     found = 1;
284                 }
285             }
286             if (found)
287                 continue;
288             if (logfiles[i].file != NULL)
289                 fclose(logfiles[i].file);
290             logfiles[i].file = fopen(logfiles[i].filename, "a");
291             if (logfiles[i].file == NULL) {
292                 error(errno, "Couldn't re-open logfile `%s'.",
293                       logfiles[i].filename);
294             }
295         }
296     }
297 
298     /*
299      * Unlock writer.
300      */
301     gw_rwlock_unlock(&rwlock);
302 }
303 
304 
log_close_all(void)305 void log_close_all(void)
306 {
307     /*
308      * Writer lock.
309      */
310     gw_rwlock_wrlock(&rwlock);
311 
312     while (num_logfiles > 0) {
313         --num_logfiles;
314         if (logfiles[num_logfiles].file != stderr && logfiles[num_logfiles].file != NULL) {
315             int i;
316             /* look for the same filename and set file to NULL */
317             for (i = num_logfiles - 1; i >= 0; i--) {
318                 if (strcmp(logfiles[num_logfiles].filename, logfiles[i].filename) == 0)
319                     logfiles[i].file = NULL;
320             }
321             fclose(logfiles[num_logfiles].file);
322             logfiles[num_logfiles].file = NULL;
323         }
324     }
325 
326     /*
327      * Unlock writer.
328      */
329     gw_rwlock_unlock(&rwlock);
330 
331     /* close syslog if used */
332     if (dosyslog) {
333         closelog();
334         dosyslog = 0;
335     }
336 }
337 
338 
log_open(char * filename,int level,enum excl_state excl)339 int log_open(char *filename, int level, enum excl_state excl)
340 {
341     FILE *f = NULL;
342     int i;
343 
344     gw_rwlock_wrlock(&rwlock);
345 
346     if (num_logfiles == MAX_LOGFILES) {
347         gw_rwlock_unlock(&rwlock);
348         error(0, "Too many log files already open, not adding `%s'",
349               filename);
350         return -1;
351     }
352 
353     if (strlen(filename) > FILENAME_MAX) {
354         gw_rwlock_unlock(&rwlock);
355         error(0, "Log filename too long: `%s'.", filename);
356         return -1;
357     }
358 
359     /*
360      * Check if the file is already opened for logging.
361      * If there is an open file, then assign the file descriptor
362      * that is already existing for this log file.
363      */
364     for (i = 0; i < num_logfiles && f == NULL; ++i) {
365         if (strcmp(logfiles[i].filename, filename) == 0)
366             f = logfiles[i].file;
367     }
368 
369     /* if not previously opened, then open it now */
370     if (f == NULL) {
371         f = fopen(filename, "a");
372         if (f == NULL) {
373             gw_rwlock_unlock(&rwlock);
374             error(errno, "Couldn't open logfile `%s'.", filename);
375             return -1;
376         }
377     }
378 
379     logfiles[num_logfiles].file = f;
380     logfiles[num_logfiles].minimum_output_level = level;
381     logfiles[num_logfiles].exclusive = excl;
382     strcpy(logfiles[num_logfiles].filename, filename);
383     ++num_logfiles;
384     i = num_logfiles - 1;
385     gw_rwlock_unlock(&rwlock);
386 
387     info(0, "Added logfile `%s' with level `%d'.", filename, level);
388 
389     return i;
390 }
391 
392 
393 #define FORMAT_SIZE (1024)
format(char * buf,int level,const char * place,int e,const char * fmt,int with_timestamp_and_pid)394 static void format(char *buf, int level, const char *place, int e,
395 		   const char *fmt, int with_timestamp_and_pid)
396 {
397     static char *tab[] = {
398         "DEBUG: ",
399         "INFO: ",
400         "WARNING: ",
401         "ERROR: ",
402         "PANIC: ",
403         "LOG: "
404     };
405     static int tab_size = sizeof(tab) / sizeof(tab[0]);
406     time_t t;
407     struct tm tm;
408     char *p, prefix[1024];
409     long tid, pid;
410 
411     p = prefix;
412 
413     if (with_timestamp_and_pid) {
414         time(&t);
415 #if LOG_TIMESTAMP_LOCALTIME
416         tm = gw_localtime(t);
417 #else
418         tm = gw_gmtime(t);
419 #endif
420         sprintf(p, "%04d-%02d-%02d %02d:%02d:%02d ",
421         tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday,
422         tm.tm_hour, tm.tm_min, tm.tm_sec);
423 
424         p = strchr(p, '\0');
425 
426         /* print PID and thread ID */
427         gwthread_self_ids(&tid, &pid);
428         sprintf(p, "[%ld] [%ld] ", pid, tid);
429     } else {
430         /* thread ID only */
431         tid = gwthread_self();
432         sprintf(p, "[%ld] ", tid);
433     }
434 
435     p = strchr(p, '\0');
436     if (level < 0 || level >= tab_size)
437         sprintf(p, "UNKNOWN: ");
438     else
439         sprintf(p, "%s", tab[level]);
440 
441     p = strchr(p, '\0');
442     if (place != NULL && *place != '\0')
443         sprintf(p, "%s: ", place);
444 
445     if (strlen(prefix) + strlen(fmt) > FORMAT_SIZE / 2) {
446         sprintf(buf, "%s <OUTPUT message too long>\n", prefix);
447         return;
448     }
449 
450     if (e == 0)
451         sprintf(buf, "%s%s\n", prefix, fmt);
452     else
453         sprintf(buf, "%s%s\n%sSystem error %d: %s\n",
454                 prefix, fmt, prefix, e, strerror(e));
455 }
456 
457 
output(FILE * f,char * buf,va_list args)458 static void PRINTFLIKE(2,0) output(FILE *f, char *buf, va_list args)
459 {
460     vfprintf(f, buf, args);
461     fflush(f);
462 }
463 
464 
kannel_syslog(char * format,va_list args,int level)465 static void PRINTFLIKE(1,0) kannel_syslog(char *format, va_list args, int level)
466 {
467     char buf[4096]; /* Trying to syslog more than 4K could be bad */
468     int translog;
469 
470     if (level >= sysloglevel && dosyslog) {
471         vsnprintf(buf, sizeof(buf), format, args);
472         /* XXX vsnprint not 100% portable */
473 
474         switch(level) {
475             case GW_DEBUG:
476                 translog = LOG_DEBUG;
477                 break;
478             case GW_INFO:
479                 translog = LOG_INFO;
480                 break;
481             case GW_WARNING:
482                 translog = LOG_WARNING;
483                 break;
484             case GW_ERROR:
485                 translog = LOG_ERR;
486                 break;
487             case GW_PANIC:
488                 translog = LOG_ALERT;
489                 break;
490             default:
491                 translog = LOG_INFO;
492                 break;
493         }
494         syslog(translog, "%s", buf);
495     }
496 }
497 
498 
499 /*
500  * Almost all of the message printing functions are identical, except for
501  * the output level they use. This macro contains the identical parts of
502  * the functions so that the code needs to exist only once. It's a bit
503  * more awkward to edit, but that can't be helped. The "do {} while (0)"
504  * construct is a gimmick to be more like a function call in all syntactic
505  * situation.
506  */
507 
508 #define FUNCTION_GUTS(level, place) \
509 	do { \
510 	    int i; \
511 	    int formatted = 0; \
512 	    char buf[FORMAT_SIZE]; \
513 	    va_list args; \
514 	    \
515             gw_rwlock_rdlock(&rwlock); \
516 	    for (i = 0; i < num_logfiles; ++i) { \
517 		if (logfiles[i].exclusive == GW_NON_EXCL && \
518                     level >= logfiles[i].minimum_output_level && \
519                     logfiles[i].file != NULL) { \
520                 	if (!formatted) { \
521                 	    format(buf, level, place, err, fmt, 1); \
522                 	    formatted = 1; \
523                 	} \
524 		        va_start(args, fmt); \
525 		        output(logfiles[i].file, buf, args); \
526 		        va_end(args); \
527 		} \
528 	    } \
529             gw_rwlock_unlock(&rwlock); \
530 	    if (dosyslog) { \
531 	        format(buf, level, place, err, fmt, 0); \
532 		va_start(args, fmt); \
533 		kannel_syslog(buf,args,level); \
534 		va_end(args); \
535 	    } \
536 	} while (0)
537 
538 #define FUNCTION_GUTS_EXCL(level, place) \
539 	do { \
540 	    char buf[FORMAT_SIZE]; \
541 	    va_list args; \
542 	    \
543             gw_rwlock_rdlock(&rwlock); \
544             if (logfiles[e].exclusive == GW_EXCL && \
545                 level >= logfiles[e].minimum_output_level && \
546                 logfiles[e].file != NULL) { \
547                 format(buf, level, place, err, fmt, 1); \
548                 va_start(args, fmt); \
549                 output(logfiles[e].file, buf, args); \
550                 va_end(args); \
551             } \
552             gw_rwlock_unlock(&rwlock); \
553 	} while (0)
554 
555 
556 #ifdef HAVE_BACKTRACE
gw_panic_output(int err,const char * fmt,...)557 static void PRINTFLIKE(2,3) gw_panic_output(int err, const char *fmt, ...)
558 {
559     FUNCTION_GUTS(GW_PANIC, "");
560 }
561 #endif
562 
gw_backtrace(void ** stack_frames,size_t size,int lock)563 void gw_backtrace(void **stack_frames, size_t size, int lock)
564 {
565 #if HAVE_BACKTRACE
566     void *frames[50];
567     size_t i;
568     char **strings;
569 
570     if (stack_frames == NULL) {
571         stack_frames = frames;
572         size = backtrace(stack_frames, sizeof(frames) / sizeof(void*));
573     }
574 
575     strings = backtrace_symbols(stack_frames, size);
576 
577     if (strings) {
578         for (i = 0; i < size; i++)
579             gw_panic_output(0, "%s", strings[i]);
580     }
581     else { /* hmm, no memory available */
582         for (i = 0; i < size; i++)
583             gw_panic_output(0, "%p", stack_frames[i]);
584     }
585 
586     /*
587      * Note: we must call gw_native_free directly because if gw_free points to gw_check_free we could
588      *       panic's and we have endless loop with SEGFAULT at the end.
589      */
590     gw_native_free(strings);
591 #endif
592 }
593 
gw_panic(int err,const char * fmt,...)594 void gw_panic(int err, const char *fmt, ...)
595 {
596     /*
597      * we don't want PANICs to spread accross smsc logs, so
598      * this will be always within the main core log.
599      */
600     FUNCTION_GUTS(GW_PANIC, "");
601 
602     gw_backtrace(NULL, 0, 0);
603 
604 #ifdef SEGFAULT_PANIC
605     *((char*)0) = 0;
606 #endif
607 
608     exit(EXIT_FAILURE);
609 }
610 
611 
error(int err,const char * fmt,...)612 void error(int err, const char *fmt, ...)
613 {
614     int e;
615 
616     if ((e = thread_to[thread_slot()])) {
617         FUNCTION_GUTS_EXCL(GW_ERROR, "");
618     } else {
619         FUNCTION_GUTS(GW_ERROR, "");
620     }
621 }
622 
623 
warning(int err,const char * fmt,...)624 void warning(int err, const char *fmt, ...)
625 {
626     int e;
627 
628     if ((e = thread_to[thread_slot()])) {
629         FUNCTION_GUTS_EXCL(GW_WARNING, "");
630     } else {
631         FUNCTION_GUTS(GW_WARNING, "");
632     }
633 }
634 
635 
info(int err,const char * fmt,...)636 void info(int err, const char *fmt, ...)
637 {
638     int e;
639 
640     if ((e = thread_to[thread_slot()])) {
641         FUNCTION_GUTS_EXCL(GW_INFO, "");
642     } else {
643         FUNCTION_GUTS(GW_INFO, "");
644     }
645 }
646 
647 
place_matches(const char * place,const char * pat)648 static int place_matches(const char *place, const char *pat)
649 {
650     size_t len;
651 
652     len = strlen(pat);
653     if (pat[len-1] == '*')
654         return (strncasecmp(place, pat, len - 1) == 0);
655 
656     return (strcasecmp(place, pat) == 0);
657 }
658 
659 
place_should_be_logged(const char * place)660 static int place_should_be_logged(const char *place)
661 {
662     int i;
663 
664     if (num_places == 0)
665 	return 1;
666     for (i = 0; i < num_places; ++i) {
667         if (*loggable_places[i] != '-' &&
668             place_matches(place, loggable_places[i]))
669             return 1;
670     }
671     return 0;
672 }
673 
674 
place_is_not_logged(const char * place)675 static int place_is_not_logged(const char *place)
676 {
677     int i;
678 
679     if (num_places == 0)
680 	return 0;
681     for (i = 0; i < num_places; ++i) {
682         if (*loggable_places[i] == '-' &&
683             place_matches(place, loggable_places[i]+1))
684             return 1;
685     }
686     return 0;
687 }
688 
689 
debug(const char * place,int err,const char * fmt,...)690 void debug(const char *place, int err, const char *fmt, ...)
691 {
692     int e;
693 
694     if (place_should_be_logged(place) && place_is_not_logged(place) == 0) {
695 	/*
696 	 * Note: giving `place' to FUNCTION_GUTS makes log lines
697     	 * too long and hard to follow. We'll rely on an external
698     	 * list of what places are used instead of reading them
699     	 * from the log file.
700 	 */
701         if ((e = thread_to[thread_slot()])) {
702             FUNCTION_GUTS_EXCL(GW_DEBUG, "");
703         } else {
704             FUNCTION_GUTS(GW_DEBUG, "");
705         }
706     }
707 }
708 
709 
log_set_debug_places(const char * places)710 void log_set_debug_places(const char *places)
711 {
712     char *p;
713 
714     p = strtok(gw_strdup(places), " ,");
715     num_places = 0;
716     while (p != NULL && num_places < MAX_LOGGABLE_PLACES) {
717         loggable_places[num_places++] = p;
718         p = strtok(NULL, " ,");
719     }
720 }
721 
722 
log_thread_to(unsigned int idx)723 void log_thread_to(unsigned int idx)
724 {
725     long thread_id = thread_slot();
726 
727     if (idx > 0)
728         info(0, "Logging thread `%ld' to logfile `%s' with level `%d'.",
729              thread_id, logfiles[idx].filename, logfiles[idx].minimum_output_level);
730     thread_to[thread_id] = idx;
731 }
732