X-Git-Url: https://arthur.barton.de/cgi-bin/gitweb.cgi?a=blobdiff_plain;f=libatalk%2Futil%2Flogger.c;h=e13ada1750a8019900f9856ea6f8c902a7746768;hb=465246e257d9aff9855e3e35d8fd5983db932b45;hp=b124142b4fe59cb5646ea3a526167395b9d25c3c;hpb=847fac2252e1320f8fdf55179ccf95a70fb532d2;p=netatalk.git diff --git a/libatalk/util/logger.c b/libatalk/util/logger.c index b124142b..e13ada17 100644 --- a/libatalk/util/logger.c +++ b/libatalk/util/logger.c @@ -31,67 +31,112 @@ Netatalk 2001 (c) #include #include -#define LOGGER_C #include -#undef LOGGER_C #define OPEN_LOGS_AS_UID 0 #define COUNT_ARRAY(array) (sizeof((array))/sizeof((array)[0])) +#define MAXLOGSIZE 512 + +#define LOGLEVEL_STRING_IDENTIFIERS { \ + "LOG_NOTHING", \ + "LOG_SEVERE", \ + "LOG_ERROR", \ + "LOG_WARN", \ + "LOG_NOTE", \ + "LOG_INFO", \ + "LOG_DEBUG", \ + "LOG_DEBUG6", \ + "LOG_DEBUG7", \ + "LOG_DEBUG8", \ + "LOG_DEBUG9", \ + "LOG_MAXDEBUG"} + +/* these are the string identifiers corresponding to each logtype */ +#define LOGTYPE_STRING_IDENTIFIERS { \ + "Default", \ + "Logger", \ + "CNID", \ + "AFPDaemon", \ + "DSI", \ + "ATalkDaemon", \ + "PAPDaemon", \ + "UAMS", \ + "end_of_list_marker"} \ + /* ========================================================================= Config ========================================================================= */ -/* Main log config container, must be globally visible */ -log_config_t log_config = { - 0, /* Initialized ? 0 = no */ - 0, /* No filelogging setup yet */ - {0}, /* processname */ - 0, /* syslog opened ? */ - logfacility_daemon, /* syslog facility to use */ - logoption_ndelay|logoption_pid, /* logging options for syslog */ - 0 /* log level for syslog */ -}; +/* Main log config container */ +log_config_t log_config = { 0 }; /* Default log config: log nothing to files. - 0: not set individually - NULL: Name of file - -1: logfiles fd - 0: Log Level - 0: Display options */ -#define DEFAULT_LOG_CONFIG {0, NULL, -1, 0, 0} - -filelog_conf_t file_configs[logtype_end_of_list_marker] = { + 0: set ? + 0: syslog ? + -1: logfiles fd + log_none: no logging by default + 0: Display options */ +#define DEFAULT_LOG_CONFIG {0, 0, -1, log_none, 0} + +UAM_MODULE_EXPORT logtype_conf_t type_configs[logtype_end_of_list_marker] = { DEFAULT_LOG_CONFIG, /* logtype_default */ - DEFAULT_LOG_CONFIG, /* logtype_core */ DEFAULT_LOG_CONFIG, /* logtype_logger */ DEFAULT_LOG_CONFIG, /* logtype_cnid */ DEFAULT_LOG_CONFIG, /* logtype_afpd */ + DEFAULT_LOG_CONFIG, /* logtype_dsi */ DEFAULT_LOG_CONFIG, /* logtype_atalkd */ DEFAULT_LOG_CONFIG, /* logtype_papd */ - DEFAULT_LOG_CONFIG /* logtype_uams */ + DEFAULT_LOG_CONFIG /* logtype_uams */ }; +/* We use this in order to track the last n log messages in order to prevent flooding */ +#define LOG_FLOODING_MINCOUNT 5 /* this controls after how many consecutive messages must be detected + before we start to hide them */ +#define LOG_FLOODING_MAXCOUNT 1000 /* this controls after how many consecutive messages we force a + "repeated x times" message */ +#define LOG_FLOODING_ARRAY_SIZE 3 /* this contols how many messages in flow we track */ +struct log_flood_entry { + int count; + unsigned int hash; +}; +static struct log_flood_entry log_flood_array[LOG_FLOODING_ARRAY_SIZE]; +static int log_flood_entries; + /* These are used by the LOG macro to store __FILE__ and __LINE__ */ -char *log_src_filename; -int log_src_linenumber; +static const char *log_src_filename; +static int log_src_linenumber; /* Array to store text to list given a log type */ static const char *arr_logtype_strings[] = LOGTYPE_STRING_IDENTIFIERS; -static const int num_logtype_strings = COUNT_ARRAY(arr_logtype_strings); +static const unsigned int num_logtype_strings = COUNT_ARRAY(arr_logtype_strings); /* Array for charachters representing log severity in the log file */ static const char arr_loglevel_chars[] = {'-','S', 'E', 'W', 'N', 'I', 'D'}; -static const int num_loglevel_chars = COUNT_ARRAY(arr_loglevel_chars); +static const unsigned int num_loglevel_chars = COUNT_ARRAY(arr_loglevel_chars); static const char *arr_loglevel_strings[] = LOGLEVEL_STRING_IDENTIFIERS; -static const int num_loglevel_strings = COUNT_ARRAY(arr_loglevel_strings); +static const unsigned int num_loglevel_strings = COUNT_ARRAY(arr_loglevel_strings); /* ========================================================================= Internal function definitions ========================================================================= */ +/* Hash a log message */ +static unsigned int hash_message(const char *message) +{ + const char *p = message; + unsigned int hash = 0, i = 7; + + while (*p) { + hash += *p * i; + i++; + p++; + } + return hash; +} + /* * If filename == NULL its for syslog logging, otherwise its for file-logging. * "unsetuplog" calls with loglevel == NULL. @@ -101,11 +146,9 @@ static const int num_loglevel_strings = COUNT_ARRAY(arr_loglevel_strings); * else * set to default logging */ - -/* -[un]setuplog []*/ static void setuplog_internal(const char *loglevel, const char *logtype, const char *filename) { - int typenum, levelnum; + unsigned int typenum, levelnum; /* Parse logtype */ for( typenum=0; typenum < num_logtype_strings; typenum++) { @@ -132,9 +175,10 @@ static void setuplog_internal(const char *loglevel, const char *logtype, const c /* is this a syslog setup or a filelog setup ? */ if (filename == NULL) { /* must be syslog */ - syslog_setup(levelnum, 0, - log_config.syslog_display_options, - log_config.facility); + syslog_setup(levelnum, + typenum, + logoption_ndelay | logoption_pid, + logfacility_daemon); } else { /* this must be a filelog */ log_setup(filename, levelnum, typenum); @@ -196,6 +240,7 @@ static void generate_message_details(char *message_details_buffer, templen = snprintf(ptr, len, " (D%d:", loglevel - 1); else templen = snprintf(ptr, len, " (%c:", arr_loglevel_chars[loglevel]); + if (templen == -1 || templen >= len) return; len -= templen; @@ -209,9 +254,9 @@ static void generate_message_details(char *message_details_buffer, len -= templen; ptr += templen; } - + strncat(ptr, "): ", len); - ptr[len] = 0; + ptr[len -1] = 0; } static int get_syslog_equivalent(enum loglevels loglevel) @@ -241,9 +286,10 @@ static int get_syslog_equivalent(enum loglevels loglevel) void log_init(void) { - syslog_setup(log_note, 0, - log_config.syslog_display_options, - log_config.facility); + syslog_setup(log_info, + logtype_default, + logoption_ndelay | logoption_pid, + logfacility_daemon); } void log_setup(const char *filename, enum loglevels loglevel, enum logtypes logtype) @@ -252,26 +298,22 @@ void log_setup(const char *filename, enum loglevels loglevel, enum logtypes logt if (loglevel == 0) { /* Disable */ - if (file_configs[logtype].set) { - if (file_configs[logtype].filename) { - free(file_configs[logtype].filename); - file_configs[logtype].filename = NULL; - } - close(file_configs[logtype].fd); - file_configs[logtype].fd = -1; - file_configs[logtype].level = 0; - file_configs[logtype].set = 0; + if (type_configs[logtype].set) { + if (type_configs[logtype].fd != -1) + close(type_configs[logtype].fd); + type_configs[logtype].fd = -1; + type_configs[logtype].level = -1; + type_configs[logtype].set = false; /* if disabling default also set all "default using" levels to 0 */ if (logtype == logtype_default) { while (logtype != logtype_end_of_list_marker) { - if ( ! (file_configs[logtype].set)) - file_configs[logtype].level = 0; + if ( ! (type_configs[logtype].set)) + type_configs[logtype].level = -1; logtype++; } } } - return; } @@ -280,51 +322,70 @@ void log_setup(const char *filename, enum loglevels loglevel, enum logtypes logt return; /* Resetting existing config ? */ - if (file_configs[logtype].set && file_configs[logtype].filename) { - free(file_configs[logtype].filename); - file_configs[logtype].filename = NULL; - close(file_configs[logtype].fd); - file_configs[logtype].fd = -1; - file_configs[logtype].level = 0; - file_configs[logtype].set = 0; + if (type_configs[logtype].set) { + if (type_configs[logtype].fd != -1) + close(type_configs[logtype].fd); + type_configs[logtype].fd = -1; + type_configs[logtype].level = -1; + type_configs[logtype].set = false; + type_configs[logtype].syslog = false; + + /* Reset configs using default */ + if (logtype == logtype_default) { + int typeiter = 0; + while (typeiter != logtype_end_of_list_marker) { + if (type_configs[typeiter].set == false) { + type_configs[typeiter].level = -1; + type_configs[typeiter].syslog = false; + } + typeiter++; + } + } } /* Set new values */ - file_configs[logtype].filename = strdup(filename); - file_configs[logtype].level = loglevel; - + type_configs[logtype].level = loglevel; /* Open log file as OPEN_LOGS_AS_UID*/ - process_uid = geteuid(); - if (process_uid) { - if (seteuid(OPEN_LOGS_AS_UID) == -1) { - /* XXX failing silently */ - return; + + /* Is it /dev/tty ? */ + if (strcmp(filename, "/dev/tty") == 0) { + type_configs[logtype].fd = 1; /* stdout */ + + /* Does it end in "XXXXXX" ? debug reguest via SIGINT */ + } else if (strcmp(filename + strlen(filename) - 6, "XXXXXX") == 0) { + char *tmp = strdup(filename); + type_configs[logtype].fd = mkstemp(tmp); + free(tmp); + + } else { + process_uid = geteuid(); + if (process_uid) { + if (seteuid(OPEN_LOGS_AS_UID) == -1) { + process_uid = 0; + } } - } - file_configs[logtype].fd = open( file_configs[logtype].filename, - O_CREAT | O_WRONLY | O_APPEND, - S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); - if (process_uid) { - if (seteuid(process_uid) == -1) { - LOG(log_error, logtype_logger, "can't seteuid back %s", strerror(errno)); - exit(EXITERR_SYS); + type_configs[logtype].fd = open(filename, + O_CREAT | O_WRONLY | O_APPEND, + S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); + if (process_uid) { + if (seteuid(process_uid) == -1) { + LOG(log_error, logtype_logger, "can't seteuid back %s", strerror(errno)); + exit(EXITERR_SYS); + } } } /* Check for error opening/creating logfile */ - if (-1 == file_configs[logtype].fd) { - free(file_configs[logtype].filename); - file_configs[logtype].filename = NULL; - file_configs[logtype].level = -1; - file_configs[logtype].set = 0; + if (type_configs[logtype].fd == -1) { + type_configs[logtype].level = -1; + type_configs[logtype].set = false; return; } - fcntl(file_configs[logtype].fd, F_SETFD, FD_CLOEXEC); - file_configs[logtype].set = 1; - log_config.filelogging = 1; - log_config.inited = 1; + fcntl(type_configs[logtype].fd, F_SETFD, FD_CLOEXEC); + type_configs[logtype].set = true; + log_config.inited = true; /* Here's how we make it possible to LOG to a logtype like "logtype_afpd" */ /* which then uses the default logtype setup if it isn't setup itself: */ @@ -334,25 +395,45 @@ void log_setup(const char *filename, enum loglevels loglevel, enum logtypes logt /* in order to make it easy and fast to check the loglevels in the LOG macro! */ if (logtype == logtype_default) { - while (logtype != logtype_end_of_list_marker) { - if ( ! (file_configs[logtype].set)) - file_configs[logtype].level = loglevel; - logtype++; + int typeiter = 0; + while (typeiter != logtype_end_of_list_marker) { + if ( ! (type_configs[typeiter].set)) + type_configs[typeiter].level = loglevel; + typeiter++; } - logtype = logtype_default; } LOG(log_debug, logtype_logger, "Setup file logging: type: %s, level: %s, file: %s", - arr_logtype_strings[logtype], arr_loglevel_strings[loglevel], file_configs[logtype].filename); + arr_logtype_strings[logtype], arr_loglevel_strings[loglevel], filename); } -/* logtype is ignored, it's just one for all */ -void syslog_setup(int loglevel, enum logtypes logtype _U_, - int display_options, int facility) +/* Setup syslog logging */ +void syslog_setup(int loglevel, enum logtypes logtype, int display_options, int facility) { - log_config.syslog_level = loglevel; + /* + * FIXME: + * this currently doesn't care if logtype is already logging to a file. + * Fortunately currently there's no way a user could trigger this as afpd.conf + * is not re-read on SIGHUP. + */ + + type_configs[logtype].level = loglevel; + type_configs[logtype].set = true; + type_configs[logtype].syslog = true; log_config.syslog_display_options = display_options; - log_config.facility = facility; + log_config.syslog_facility = facility; + + /* Setting default logging? Then set all logtype not set individually */ + if (logtype == logtype_default) { + int typeiter = 0; + while (typeiter != logtype_end_of_list_marker) { + if ( ! (type_configs[typeiter].set)) { + type_configs[typeiter].level = loglevel; + type_configs[typeiter].syslog = true; + } + typeiter++; + } + } log_config.inited = 1; @@ -371,13 +452,26 @@ void set_processname(const char *processname) log_config.processname[15] = 0; } +/* Called by the LOG macro for syslog messages */ +static void make_syslog_entry(enum loglevels loglevel, enum logtypes logtype _U_, char *message) +{ + if ( !log_config.syslog_opened ) { + openlog(log_config.processname, + log_config.syslog_display_options, + log_config.syslog_facility); + log_config.syslog_opened = true; + } + + syslog(get_syslog_equivalent(loglevel), "%s", message); +} + /* ------------------------------------------------------------------------- make_log_entry has 1 main flaws: The message in its entirity, must fit into the tempbuffer. So it must be shorter than MAXLOGSIZE ------------------------------------------------------------------------- */ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, - char *message, ...) + const char *file, int line, char *message, ...) { /* fn is not reentrant but is used in signal handler * with LOGGER it's a little late source name and line number @@ -392,20 +486,43 @@ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, if (inlog) return; + inlog = 1; + + if (!log_config.inited) { + log_init(); + } + + if (type_configs[logtype].syslog) { + if (type_configs[logtype].level >= loglevel) { + /* Initialise the Messages and send it to syslog */ + va_start(args, message); + vsnprintf(temp_buffer, MAXLOGSIZE -1, message, args); + va_end(args); + temp_buffer[MAXLOGSIZE -1] = 0; + make_syslog_entry(loglevel, logtype, temp_buffer); + } + inlog = 0; + return; + } + + /* logging to a file */ + + log_src_filename = file; + log_src_linenumber = line; + /* Check if requested logtype is setup */ - if (file_configs[logtype].set) + if (type_configs[logtype].set) /* Yes */ - fd = file_configs[logtype].fd; + fd = type_configs[logtype].fd; else /* No: use default */ - fd = file_configs[logtype_default].fd; + fd = type_configs[logtype_default].fd; if (fd < 0) { /* no where to send the output, give up */ - return; + goto exit; } - inlog = 1; /* Initialise the Messages */ va_start(args, message); len = vsnprintf(temp_buffer, MAXLOGSIZE -1, message, args); @@ -422,57 +539,92 @@ void make_log_entry(enum loglevels loglevel, enum logtypes logtype, temp_buffer[len+1] = 0; } - generate_message_details(log_details_buffer, sizeof(log_details_buffer), - file_configs[logtype].set ? - file_configs[logtype].display_options : - file_configs[logtype_default].display_options, - loglevel, logtype); + if (type_configs[logtype].level >= log_debug) + goto log; /* bypass flooding checks */ + goto log; + /* Prevent flooding: hash the message and check if we got the same one recently */ + int hash = hash_message(temp_buffer) + log_src_linenumber; - /* If default wasnt setup its fd is -1 */ - iov[0].iov_base = log_details_buffer; - iov[0].iov_len = strlen(log_details_buffer); - iov[1].iov_base = temp_buffer; - iov[1].iov_len = strlen(temp_buffer); - writev( fd, iov, 2); + /* Search for the same message by hash */ + for (int i = log_flood_entries - 1; i >= 0; i--) { + if (log_flood_array[i].hash == hash) { - inlog = 0; -} + /* found same message */ + log_flood_array[i].count++; -/* Called by the LOG macro for syslog messages */ -void make_syslog_entry(enum loglevels loglevel, enum logtypes logtype _U_, char *message, ...) -{ - va_list args; - char log_buffer[MAXLOGSIZE]; - /* fn is not reentrant but is used in signal handler - * with LOGGER it's a little late source name and line number - * are already changed. - */ - static int inlog = 0; + /* Check if that message has reached LOG_FLOODING_MAXCOUNT */ + if (log_flood_array[i].count >= LOG_FLOODING_MAXCOUNT) { + /* yes, log it and remove from array */ - if (inlog) - return; - inlog = 1; + /* reusing log_details_buffer */ + sprintf(log_details_buffer, "message repeated %i times\n", + LOG_FLOODING_MAXCOUNT - 1); + write(fd, log_details_buffer, strlen(log_details_buffer)); - if ( ! (log_config.syslog_opened) ) { - openlog(log_config.processname, log_config.syslog_display_options, - log_config.facility); - log_config.syslog_opened = 1; - } + if ((i + 1) == LOG_FLOODING_ARRAY_SIZE) { + /* last array element, just decrement count */ + log_flood_entries--; + goto exit; + } + /* move array elements down */ + for (int j = i + 1; j != LOG_FLOODING_ARRAY_SIZE ; j++) + log_flood_array[j-1] = log_flood_array[j]; + log_flood_entries--; + } - /* Initialise the Messages */ - va_start(args, message); - vsnprintf(log_buffer, sizeof(log_buffer), message, args); - va_end(args); - log_buffer[MAXLOGSIZE -1] = 0; - syslog(get_syslog_equivalent(loglevel), "%s", log_buffer); + if (log_flood_array[i].count < LOG_FLOODING_MINCOUNT) + /* log it */ + goto log; + /* discard it */ + goto exit; + } /* if */ + } /* for */ + + /* No matching message found, add this message to array*/ + if (log_flood_entries == LOG_FLOODING_ARRAY_SIZE) { + /* array is full, discard oldest entry printing "message repeated..." if count > 1 */ + if (log_flood_array[0].count >= LOG_FLOODING_MINCOUNT) { + /* reusing log_details_buffer */ + sprintf(log_details_buffer, "message repeated %i times\n", + log_flood_array[0].count - LOG_FLOODING_MINCOUNT + 1); + write(fd, log_details_buffer, strlen(log_details_buffer)); + } + for (int i = 1; i < LOG_FLOODING_ARRAY_SIZE; i++) { + log_flood_array[i-1] = log_flood_array[i]; + } + log_flood_entries--; + } + log_flood_array[log_flood_entries].count = 1; + log_flood_array[log_flood_entries].hash = hash; + log_flood_entries++; + +log: + if ( ! log_config.console) { + generate_message_details(log_details_buffer, sizeof(log_details_buffer), + type_configs[logtype].set ? + type_configs[logtype].display_options : + type_configs[logtype_default].display_options, + loglevel, logtype); + + /* If default wasnt setup its fd is -1 */ + iov[0].iov_base = log_details_buffer; + iov[0].iov_len = strlen(log_details_buffer); + iov[1].iov_base = temp_buffer; + iov[1].iov_len = strlen(temp_buffer); + writev( fd, iov, 2); + } else { + write(fd, temp_buffer, strlen(temp_buffer)); + } +exit: inlog = 0; } + void setuplog(const char *logstr) { - char *ptr, *ptrbak, *logtype, *loglevel, *filename; + char *ptr, *ptrbak, *logtype, *loglevel = NULL, *filename = NULL; ptr = strdup(logstr); ptrbak = ptr; @@ -495,6 +647,8 @@ void setuplog(const char *logstr) ptr++; } filename = ptr; + if (filename && *filename == 0) + filename = NULL; } /* finally call setuplog, filename can be NULL */