From f958b2a1977520d858f850b69d738b5c49a6a7e8 Mon Sep 17 00:00:00 2001 From: Richard Fuchs Date: Mon, 28 Nov 2016 08:41:51 -0500 Subject: [PATCH] split logging mechanism into separate common files Change-Id: I92dd843db2d1b5719e7809ce7d151d08c53938f2 --- daemon/Makefile | 2 +- daemon/log.c | 200 ++------------------------------- daemon/log.h | 55 +--------- daemon/loglib.c | 1 + lib/loglib.c | 225 ++++++++++++++++++++++++++++++++++++++ lib/loglib.h | 69 ++++++++++++ recording-daemon/Makefile | 2 +- recording-daemon/log.h | 4 +- recording-daemon/loglib.c | 1 + recording-daemon/main.c | 4 +- 10 files changed, 315 insertions(+), 248 deletions(-) create mode 120000 daemon/loglib.c create mode 100644 lib/loglib.c create mode 100644 lib/loglib.h create mode 120000 recording-daemon/loglib.c diff --git a/daemon/Makefile b/daemon/Makefile index a1a2c02ad..a2bcdd889 100644 --- a/daemon/Makefile +++ b/daemon/Makefile @@ -68,7 +68,7 @@ endif SRCS= main.c kernel.c poller.c aux.c control_tcp.c streambuf.c call.c control_udp.c redis.c \ bencode.c cookie_cache.c udp_listener.c control_ng.c sdp.c str.c stun.c rtcp.c \ crypto.c rtp.c call_interfaces.c dtls.c log.c cli.c graphite.c ice.c socket.c \ - media_socket.c rtcp_xr.c homer.c recording.c rtplib.c + media_socket.c rtcp_xr.c homer.c recording.c rtplib.c loglib.c OBJS= $(SRCS:.c=.o) diff --git a/daemon/log.c b/daemon/log.c index c364b376b..450da4d55 100644 --- a/daemon/log.c +++ b/daemon/log.c @@ -7,156 +7,45 @@ #include "call.h" #include "poller.h" #include "ice.h" +#include "loglib.h" -struct log_limiter_entry { - char *prefix; - char *msg; -}; - - - struct log_info __thread log_info; -#ifndef __DEBUG -volatile gint log_level = LOG_INFO; -#else -volatile gint log_level = LOG_DEBUG; -#endif - -static write_log_t log_both; - -unsigned int max_log_line_length = 500; -write_log_t *write_log = (write_log_t *) log_both; - - -const _fac_code_t _facilitynames[] = - { - { "auth", LOG_AUTH }, - { "authpriv", LOG_AUTHPRIV }, - { "cron", LOG_CRON }, - { "daemon", LOG_DAEMON }, - { "ftp", LOG_FTP }, - { "kern", LOG_KERN }, - { "lpr", LOG_LPR }, - { "mail", LOG_MAIL }, - { "news", LOG_NEWS }, - { "syslog", LOG_SYSLOG }, - { "user", LOG_USER }, - { "uucp", LOG_UUCP }, - { "local0", LOG_LOCAL0 }, - { "local1", LOG_LOCAL1 }, - { "local2", LOG_LOCAL2 }, - { "local3", LOG_LOCAL3 }, - { "local4", LOG_LOCAL4 }, - { "local5", LOG_LOCAL5 }, - { "local6", LOG_LOCAL6 }, - { "local7", LOG_LOCAL7 }, - { NULL, -1 } - }; -static const char* const prio_str[] = { - "EMERG", - "ALERT", - "CRIT", - "ERR", - "WARNING", - "NOTICE", - "INFO", - "DEBUG" - }; - -gboolean _log_stderr = 0; -int _log_facility = LOG_DAEMON; int _log_facility_cdr = 0; int _log_facility_rtcp = 0; -static GHashTable *__log_limiter; -static mutex_t __log_limiter_lock; -static GStringChunk *__log_limiter_strings; -static unsigned int __log_limiter_count; - - -static void vlog_to_stderr(int facility_priority, char *format, va_list ap) { - char *msg; - int ret; - - ret = vasprintf(&msg, format, ap); - - if (ret < 0) { - fprintf(stderr,"ERR: Failed to print log message - message dropped\n"); - return; - } - - if (G_LIKELY(g_now.tv_sec)) - fprintf(stderr, "[%lu.%06lu] %s\n", (unsigned long) g_now.tv_sec, - (unsigned long) g_now.tv_usec, msg); - else - fprintf(stderr, "%s\n", msg); - - free(msg); -} - -void log_to_stderr(int facility_priority, char *format, ...) { - va_list ap; - - va_start(ap, format); - vlog_to_stderr(facility_priority, format, ap); - va_end(ap); -} - -static void log_both(int facility_priority, char *format, ...) { - va_list ap; - - va_start(ap, format); - vsyslog(facility_priority, format, ap); - va_end(ap); - - if (LOG_LEVEL_MASK(facility_priority) <= LOG_WARN) { - va_start(ap, format); - vlog_to_stderr(facility_priority, format, ap); - va_end(ap); - } -} void __ilog(int prio, const char *fmt, ...) { char prefix[300]; - char *msg, *piece; - const char *infix = ""; va_list ap; - int ret, xprio; - - xprio = LOG_LEVEL_MASK(prio); switch (log_info.e) { case LOG_INFO_NONE: - snprintf(prefix, sizeof(prefix),"%s: ", prio_str[prio & LOG_PRIMASK]); + prefix[0] = 0; break; case LOG_INFO_CALL: - snprintf(prefix, sizeof(prefix), "%s: ["STR_FORMAT"]: ", - prio_str[prio & LOG_PRIMASK], + snprintf(prefix, sizeof(prefix), "["STR_FORMAT"]: ", STR_FMT(&log_info.u.call->callid)); break; case LOG_INFO_STREAM_FD: if (log_info.u.stream_fd->call) - snprintf(prefix, sizeof(prefix), "%s: ["STR_FORMAT" port %5u]: ", - prio_str[prio & LOG_PRIMASK], + snprintf(prefix, sizeof(prefix), "["STR_FORMAT" port %5u]: ", STR_FMT(&log_info.u.stream_fd->call->callid), log_info.u.stream_fd->socket.local.port); break; case LOG_INFO_STR: - snprintf(prefix, sizeof(prefix), "%s: ["STR_FORMAT"]: ", - prio_str[prio & LOG_PRIMASK], + snprintf(prefix, sizeof(prefix), "["STR_FORMAT"]: ", STR_FMT(log_info.u.str)); break; case LOG_INFO_C_STRING: - snprintf(prefix, sizeof(prefix), "%s: [%s]: ", prio_str[prio & LOG_PRIMASK],log_info.u.cstr); + snprintf(prefix, sizeof(prefix), "[%s]: ", log_info.u.cstr); break; case LOG_INFO_ICE_AGENT: - snprintf(prefix, sizeof(prefix), "%s: ["STR_FORMAT"/"STR_FORMAT"/%u]: ", - prio_str[prio & LOG_PRIMASK], + snprintf(prefix, sizeof(prefix), "["STR_FORMAT"/"STR_FORMAT"/%u]: ", STR_FMT(&log_info.u.ice_agent->call->callid), STR_FMT(&log_info.u.ice_agent->media->monologue->tag), log_info.u.ice_agent->media->index); @@ -164,88 +53,15 @@ void __ilog(int prio, const char *fmt, ...) { } va_start(ap, fmt); - ret = vasprintf(&msg, fmt, ap); + __vpilog(prio, prefix, fmt, ap); va_end(ap); - - if (ret < 0) { - write_log(LOG_ERROR, "Failed to print syslog message - message dropped"); - return; - } - - while (ret > 0 && msg[ret-1] == '\n') - ret--; - - if ((prio & LOG_FLAG_LIMIT)) { - time_t when; - struct log_limiter_entry lle, *llep; - - lle.prefix = prefix; - lle.msg = msg; - - mutex_lock(&__log_limiter_lock); - - if (__log_limiter_count > 10000) { - g_hash_table_remove_all(__log_limiter); - g_string_chunk_clear(__log_limiter_strings); - __log_limiter_count = 0; - } - - when = (time_t) g_hash_table_lookup(__log_limiter, &lle); - if (!when || (poller_now - when) >= 15) { - lle.prefix = g_string_chunk_insert(__log_limiter_strings, prefix); - lle.msg = g_string_chunk_insert(__log_limiter_strings, msg); - llep = (void *) g_string_chunk_insert_len(__log_limiter_strings, - (void *) &lle, sizeof(lle)); - g_hash_table_insert(__log_limiter, llep, (void *) poller_now); - __log_limiter_count++; - when = 0; - } - - mutex_unlock(&__log_limiter_lock); - - if (when) - goto out; - } - - piece = msg; - - while (max_log_line_length && ret > max_log_line_length) { - write_log(xprio, "%s%s%.*s ...", prefix, infix, max_log_line_length, piece); - ret -= max_log_line_length; - piece += max_log_line_length; - infix = "... "; - } - - write_log(xprio, "%s%s%.*s", prefix, infix, ret, piece); - -out: - free(msg); } void cdrlog(const char* cdrbuffer) { syslog(LOG_INFO | _log_facility_cdr, "%s", cdrbuffer); } -static unsigned int log_limiter_entry_hash(const void *p) { - const struct log_limiter_entry *lle = p; - return g_str_hash(lle->msg) ^ g_str_hash(lle->prefix); -} - -static int log_limiter_entry_equal(const void *a, const void *b) { - const struct log_limiter_entry *A = a, *B = b; - if (!g_str_equal(A->msg, B->msg)) - return 0; - if (!g_str_equal(A->prefix, B->prefix)) - return 0; - return 1; -} void rtcplog(const char* cdrbuffer) { syslog(LOG_INFO | _log_facility_rtcp, "%s", cdrbuffer); } - -void log_init() { - mutex_init(&__log_limiter_lock); - __log_limiter = g_hash_table_new(log_limiter_entry_hash, log_limiter_entry_equal); - __log_limiter_strings = g_string_chunk_new(1024); -} diff --git a/daemon/log.h b/daemon/log.h index a3ffdef61..e617b326d 100644 --- a/daemon/log.h +++ b/daemon/log.h @@ -2,10 +2,8 @@ #define __LOG_H__ -#include -#include -#include "compat.h" #include "str.h" +#include "loglib.h" @@ -32,65 +30,20 @@ struct log_info { } e; }; -extern gboolean _log_stderr; -extern int _log_facility; extern int _log_facility_cdr; extern int _log_facility_rtcp; -typedef struct _fac_code { - char *c_name; - int c_val; -} _fac_code_t; - -extern const _fac_code_t _facilitynames[]; - -typedef void write_log_t(int facility_priority, char *format, ...) __attribute__ ((format (printf, 2, 3))); -extern write_log_t *write_log; +extern struct log_info __thread log_info; -void log_to_stderr(int facility_priority, char *format, ...) __attribute__ ((format (printf, 2, 3))); -extern struct log_info __thread log_info; -extern volatile gint log_level; -extern unsigned int max_log_line_length; - - - - -void log_init(void); -void __ilog(int prio, const char *fmt, ...)__attribute__ ((format (printf, 2, 3))); -#ifndef __DEBUG -#define ilog(prio, fmt...) \ - do { \ - int loglevel = get_log_level(); \ - if (LOG_LEVEL_MASK((prio)) > LOG_LEVEL_MASK(loglevel)) \ - break; \ - if ((loglevel & LOG_FLAG_RESTORE) && !((prio) & LOG_FLAG_RESTORE)) \ - break; \ - __ilog(prio, fmt); \ - } while (0) -#else -#define ilog(prio, fmt...) __ilog(prio, fmt) -#endif void cdrlog(const char* cdrbuffer); void rtcplog(const char* cdrbuffer); -INLINE int get_log_level(void) { - return g_atomic_int_get(&log_level); -} - - -#define LOG_ERROR LOG_ERR -#define LOG_WARN LOG_WARNING - - -#define LOG_LEVEL_MASK(v) ((v) & 0x0f) - -#define LOG_FLAG_RESTORE 0x10 -#define LOG_FLAG_LIMIT 0x20 - +#define ilog(...) __ilog(__VA_ARGS__) +void __ilog(int prio, const char *fmt, ...) __attribute__ ((format (printf, 2, 3))); #endif diff --git a/daemon/loglib.c b/daemon/loglib.c new file mode 120000 index 000000000..165fc5b41 --- /dev/null +++ b/daemon/loglib.c @@ -0,0 +1 @@ +../lib/loglib.c \ No newline at end of file diff --git a/lib/loglib.c b/lib/loglib.c new file mode 100644 index 000000000..ff99e30ed --- /dev/null +++ b/lib/loglib.c @@ -0,0 +1,225 @@ +#include "loglib.h" +#include +#include +#include +#include +#include +#include +#include +#include + + +struct log_limiter_entry { + char *prefix; + char *msg; +}; + + +#ifndef __DEBUG +volatile gint log_level = LOG_INFO; +#else +volatile gint log_level = LOG_DEBUG; +#endif + + + +static write_log_t log_both; + +unsigned int max_log_line_length = 500; +write_log_t *write_log = (write_log_t *) log_both; + + + +const _fac_code_t _facilitynames[] = + { + { "auth", LOG_AUTH }, + { "authpriv", LOG_AUTHPRIV }, + { "cron", LOG_CRON }, + { "daemon", LOG_DAEMON }, + { "ftp", LOG_FTP }, + { "kern", LOG_KERN }, + { "lpr", LOG_LPR }, + { "mail", LOG_MAIL }, + { "news", LOG_NEWS }, + { "syslog", LOG_SYSLOG }, + { "user", LOG_USER }, + { "uucp", LOG_UUCP }, + { "local0", LOG_LOCAL0 }, + { "local1", LOG_LOCAL1 }, + { "local2", LOG_LOCAL2 }, + { "local3", LOG_LOCAL3 }, + { "local4", LOG_LOCAL4 }, + { "local5", LOG_LOCAL5 }, + { "local6", LOG_LOCAL6 }, + { "local7", LOG_LOCAL7 }, + { NULL, -1 } + }; + +static const char* const prio_str[] = { + "EMERG", + "ALERT", + "CRIT", + "ERR", + "WARNING", + "NOTICE", + "INFO", + "DEBUG" + }; + +gboolean _log_stderr = 0; +int _log_facility = LOG_DAEMON; + + + +static GHashTable *__log_limiter; +static pthread_mutex_t __log_limiter_lock; +static GStringChunk *__log_limiter_strings; +static unsigned int __log_limiter_count; + + + + +static void vlog_to_stderr(int facility_priority, const char *format, va_list ap) { + char *msg; + int ret; + struct timeval tv_now; + + ret = vasprintf(&msg, format, ap); + + if (ret < 0) { + fprintf(stderr,"ERR: Failed to print log message - message dropped\n"); + return; + } + + gettimeofday(&tv_now, NULL); + + fprintf(stderr, "[%lu.%06lu] %s\n", (unsigned long) tv_now.tv_sec, + (unsigned long) tv_now.tv_usec, msg); + + free(msg); +} + +void log_to_stderr(int facility_priority, const char *format, ...) { + va_list ap; + + va_start(ap, format); + vlog_to_stderr(facility_priority, format, ap); + va_end(ap); +} + +static void log_both(int facility_priority, const char *format, ...) { + va_list ap; + + va_start(ap, format); + vsyslog(facility_priority, format, ap); + va_end(ap); + + if (LOG_LEVEL_MASK(facility_priority) <= LOG_WARN) { + va_start(ap, format); + vlog_to_stderr(facility_priority, format, ap); + va_end(ap); + } +} + + + +void __vpilog(int prio, const char *prefix, const char *fmt, va_list ap) { + char *msg, *piece; + const char *infix = ""; + int ret, xprio; + const char *prio_prefix; + + xprio = LOG_LEVEL_MASK(prio); + prio_prefix = prio_str[prio & LOG_PRIMASK]; + if (!prefix) + prefix = ""; + + ret = vasprintf(&msg, fmt, ap); + + if (ret < 0) { + write_log(LOG_ERROR, "Failed to print syslog message - message dropped"); + return; + } + + while (ret > 0 && msg[ret-1] == '\n') + ret--; + + if ((prio & LOG_FLAG_LIMIT)) { + time_t when; + struct log_limiter_entry lle, *llep; + + lle.prefix = (char *) prefix; + lle.msg = msg; + + pthread_mutex_lock(&__log_limiter_lock); + + if (__log_limiter_count > 10000) { + g_hash_table_remove_all(__log_limiter); + g_string_chunk_clear(__log_limiter_strings); + __log_limiter_count = 0; + } + + time_t now = time(NULL); + + when = (time_t) GPOINTER_TO_UINT(g_hash_table_lookup(__log_limiter, &lle)); + if (!when || (now - when) >= 15) { + lle.prefix = g_string_chunk_insert(__log_limiter_strings, prefix); + lle.msg = g_string_chunk_insert(__log_limiter_strings, msg); + llep = (void *) g_string_chunk_insert_len(__log_limiter_strings, + (void *) &lle, sizeof(lle)); + g_hash_table_insert(__log_limiter, llep, GUINT_TO_POINTER(now)); + __log_limiter_count++; + when = 0; + } + + pthread_mutex_unlock(&__log_limiter_lock); + + if (when) + goto out; + } + + piece = msg; + + while (max_log_line_length && ret > max_log_line_length) { + write_log(xprio, "%s%s%.*s ...", prefix, infix, max_log_line_length, piece); + ret -= max_log_line_length; + piece += max_log_line_length; + infix = "... "; + } + + write_log(xprio, "%s: %s%s%.*s", prio_prefix, prefix, infix, ret, piece); + +out: + free(msg); +} + + +void __ilog_np(int prio, const char *fmt, ...) { + va_list ap; + + va_start(ap, fmt); + __vpilog(prio, NULL, fmt, ap); + va_end(ap); +} + + + +static unsigned int log_limiter_entry_hash(const void *p) { + const struct log_limiter_entry *lle = p; + return g_str_hash(lle->msg) ^ g_str_hash(lle->prefix); +} + +static int log_limiter_entry_equal(const void *a, const void *b) { + const struct log_limiter_entry *A = a, *B = b; + if (!g_str_equal(A->msg, B->msg)) + return 0; + if (!g_str_equal(A->prefix, B->prefix)) + return 0; + return 1; +} + +void log_init() { + pthread_mutex_init(&__log_limiter_lock, NULL); + __log_limiter = g_hash_table_new(log_limiter_entry_hash, log_limiter_entry_equal); + __log_limiter_strings = g_string_chunk_new(1024); +} diff --git a/lib/loglib.h b/lib/loglib.h new file mode 100644 index 000000000..018e14782 --- /dev/null +++ b/lib/loglib.h @@ -0,0 +1,69 @@ +#ifndef _LOGLIB_H_ +#define _LOGLIB_H_ + + +#include +#include +#include +#include "compat.h" + + +typedef struct _fac_code { + char *c_name; + int c_val; +} _fac_code_t; + +extern const _fac_code_t _facilitynames[]; + + +extern gboolean _log_stderr; +extern int _log_facility; + + +extern volatile gint log_level; +extern unsigned int max_log_line_length; + + +typedef void write_log_t(int facility_priority, const char *format, ...) __attribute__ ((format (printf, 2, 3))); +extern write_log_t *write_log; + +void log_to_stderr(int facility_priority, const char *format, ...) __attribute__ ((format (printf, 2, 3))); + +void log_init(void); + +void __vpilog(int prio, const char *prefix, const char *fmt, va_list); +void __ilog_np(int prio, const char *format, ...) __attribute__ ((format (printf, 2, 3))); + + +#ifndef __DEBUG +#define pilog(prio, fmt...) \ + do { \ + int loglevel = get_log_level(); \ + if (LOG_LEVEL_MASK((prio)) > LOG_LEVEL_MASK(loglevel)) \ + break; \ + if ((loglevel & LOG_FLAG_RESTORE) && !((prio) & LOG_FLAG_RESTORE)) \ + break; \ + __ilog(prio, fmt); \ + } while (0) +#else +#define pilog(prio, fmt...) __ilog(prio, fmt) +#endif + + +INLINE int get_log_level(void) { + return g_atomic_int_get(&log_level); +} + + + +#define LOG_ERROR LOG_ERR +#define LOG_WARN LOG_WARNING + + +#define LOG_LEVEL_MASK(v) ((v) & 0x0f) + +#define LOG_FLAG_RESTORE 0x10 +#define LOG_FLAG_LIMIT 0x20 + + +#endif diff --git a/recording-daemon/Makefile b/recording-daemon/Makefile index d603948a3..5176513e6 100644 --- a/recording-daemon/Makefile +++ b/recording-daemon/Makefile @@ -36,7 +36,7 @@ ifneq ($(DBG),yes) endif SRCS= epoll.c garbage.c inotify.c main.c metafile.c stream.c recaux.c rtplib.c packet.c \ - decoder.c + decoder.c loglib.c OBJS= $(SRCS:.c=.o) diff --git a/recording-daemon/log.h b/recording-daemon/log.h index 71c93f2c2..8ab8eee6f 100644 --- a/recording-daemon/log.h +++ b/recording-daemon/log.h @@ -1,6 +1,7 @@ #ifndef _LOG_H_ #define _LOG_H_ +#include "loglib.h" #include #include #include @@ -9,8 +10,7 @@ #define die(fmt, ...) do { ilog(LOG_CRIT, "Fatal error: " fmt, ##__VA_ARGS__); exit(-1); } while (0) #define die_errno(msg) die("%s: %s", msg, strerror(errno)) -#define ilog(fclt, fmt, ...) fprintf(stderr, fmt "\n", ##__VA_ARGS__) -#define vilog(fclt, fmt, ap) vfprintf(stderr, fmt, ap) +#define ilog(...) __ilog_np(__VA_ARGS__) #define dbg(fmt, ...) ilog(LOG_DEBUG, fmt, ##__VA_ARGS__) #endif diff --git a/recording-daemon/loglib.c b/recording-daemon/loglib.c new file mode 120000 index 000000000..165fc5b41 --- /dev/null +++ b/recording-daemon/loglib.c @@ -0,0 +1 @@ +../lib/loglib.c \ No newline at end of file diff --git a/recording-daemon/main.c b/recording-daemon/main.c index 8b9fdfa99..c6b7718b9 100644 --- a/recording-daemon/main.c +++ b/recording-daemon/main.c @@ -13,6 +13,7 @@ #include "inotify.h" #include "metafile.h" #include "garbage.h" +#include "loglib.h" @@ -34,11 +35,12 @@ static void signals(void) { static void avlog_ilog(void *ptr, int loglevel, const char *fmt, va_list ap) { - vilog(loglevel, fmt, ap); + __vpilog(loglevel, NULL, fmt, ap); } static void setup(void) { + log_init(); av_register_all(); avcodec_register_all(); avformat_network_init();