void chassis_log_backend_log(chassis_log_backend_t *backend, gchar* logger_name, GLogLevelFlags level, const gchar *message) { gboolean is_duplicate = FALSE; const gchar *log_lvl_name; const gchar *logger_name_clean = (logger_name[0] == '\0') ? "global" : logger_name; const gchar *stripped_message = chassis_log_skip_topsrcdir(message); switch (level & G_LOG_LEVEL_MASK) { case G_LOG_LEVEL_CRITICAL: log_lvl_name = "critical"; break; case G_LOG_LEVEL_ERROR: log_lvl_name = "error"; break; case G_LOG_LEVEL_WARNING: log_lvl_name = "warning"; break; case G_LOG_LEVEL_MESSAGE: log_lvl_name = "message"; break; case G_LOG_LEVEL_INFO: log_lvl_name = "info"; break; case G_LOG_LEVEL_DEBUG: log_lvl_name = "debug"; break; case CHASSIS_LOG_LEVEL_BROADCAST: log_lvl_name = "*"; break; default: log_lvl_name = "unknown"; break; } chassis_log_backend_lock(backend); /* check for a duplicate message * never consider this to be a duplicate if the log level is INFO (which being used to force a message, e.g. in broadcasting) */ if (backend->last_msg->len > 0 && 0 == strcmp(backend->last_msg->str, stripped_message) && level != CHASSIS_LOG_LEVEL_BROADCAST && /* a broadcast */ backend->needs_compress) { is_duplicate = TRUE; } if (!is_duplicate || backend->last_msg_count > 100 || time(NULL) - backend->last_msg_ts > 30) { /* TODO: make these limits configurable */ if (backend->last_msg_count) { GString *logger_names = g_string_new(""); guint hash_size = g_hash_table_size(backend->last_loggers); if (hash_size > 0) { /* should be always true... */ GHashTableIter iter; gpointer key, value; guint i = 0; g_hash_table_iter_init(&iter, backend->last_loggers); while (g_hash_table_iter_next(&iter, &key, &value)) { g_string_append(logger_names, (gchar*)key); g_hash_table_iter_remove(&iter); if (++i < hash_size) { g_string_append(logger_names, ", "); } } } if (backend->needs_timestamp) { chassis_log_backend_update_timestamp(backend); g_string_append_len(backend->log_str, C(": ")); } g_string_append_printf(backend->log_str, "[%s] last message repeated %d times\n", logger_names->str, backend->last_msg_count); backend->log_func(backend, level, S(backend->log_str)); g_string_free(logger_names, TRUE); } if (backend->needs_timestamp) { chassis_log_backend_update_timestamp(backend); g_string_append_len(backend->log_str, C(": ")); } g_string_append_printf(backend->log_str, "[%s] (%s) %s", logger_name_clean, log_lvl_name, stripped_message); /* reset the last-logged message */ g_string_assign(backend->last_msg, stripped_message); backend->last_msg_count = 0; backend->last_msg_ts = time(NULL); /* ask the backend to perform the write */ backend->log_func(backend, level, S(backend->log_str)); } else { /* save the logger_name to print all of the coalesced logger sources later */ gchar *hash_logger_name = g_strdup(logger_name_clean); g_hash_table_insert(backend->last_loggers, hash_logger_name, hash_logger_name); backend->last_msg_count++; } chassis_log_backend_unlock(backend); }
void chassis_log_func(const gchar *UNUSED_PARAM(log_domain), GLogLevelFlags log_level, const gchar *message, gpointer user_data) { chassis_log *log = user_data; int i; gchar *log_lvl_name = "(error)"; gboolean is_duplicate = FALSE; gboolean is_log_rotated = FALSE; const char *stripped_message = chassis_log_skip_topsrcdir(message); /** * make sure we syncronize the order of the write-statements */ //static GStaticMutex log_mutex = G_STATIC_MUTEX_INIT; static GStaticMutex log_mutex = { .mutex = NULL }; /** * rotate logs straight away if log->rotate_logs is true * we do this before ignoring any log levels, so that rotation * happens straight away - see Bug#55711 */ if (-1 != log->log_file_fd) { if (log->rotate_logs) { chassis_log_close(log); chassis_log_open(log); is_log_rotated = TRUE; /* we will need to dump even duplicates */ } } /* ignore the verbose log-levels */ if (log_level > log->min_lvl) return; g_static_mutex_lock(&log_mutex); for (i = 0; log_lvl_map[i].name; i++) { if (log_lvl_map[i].lvl == log_level) { log_lvl_name = log_lvl_map[i].name; break; } } if (log->last_msg->len > 0 && 0 == strcmp(log->last_msg->str, stripped_message)) { is_duplicate = TRUE; } /** * if the log has been rotated, we always dump the last message even if it * was a duplicate. Otherwise, do not print duplicates unless they have been * ignored at least 100 times, or they were last printed greater than * 30 seconds ago. */ if (is_log_rotated || !is_duplicate || log->last_msg_count > 100 || time(NULL) - log->last_msg_ts > 30) { /* if we lave the last message repeating, log it */ if (log->last_msg_count) { chassis_log_update_timestamp(log); g_string_append_printf(log->log_ts_str, ": (%s) last message repeated %d times", log_lvl_name, log->last_msg_count); chassis_log_write(log, log_level, log->log_ts_str); } chassis_log_update_timestamp(log); g_string_append(log->log_ts_str, ": ("); g_string_append(log->log_ts_str, log_lvl_name); g_string_append(log->log_ts_str, ") "); g_string_append(log->log_ts_str, stripped_message); /* reset the last-logged message */ g_string_assign(log->last_msg, stripped_message); log->last_msg_count = 0; log->last_msg_ts = time(NULL); chassis_log_write(log, log_level, log->log_ts_str); } else { log->last_msg_count++; } log->rotate_logs = FALSE; g_static_mutex_unlock(&log_mutex); }