log: introduce context

This commit is contained in:
Justin M. Keyes 2017-09-02 11:35:53 +02:00
parent 6c53c3ee55
commit 63c6470505
3 changed files with 37 additions and 25 deletions

View File

@ -95,8 +95,12 @@ void log_unlock(void)
uv_mutex_unlock(&mutex); uv_mutex_unlock(&mutex);
} }
bool do_log(int log_level, const char *func_name, int line_num, bool eol, /// @param context description of a shared context or subsystem
const char* fmt, ...) FUNC_ATTR_UNUSED /// @param func_name function name, or NULL
/// @param line_num source line number, or -1
bool do_log(int log_level, const char *context, const char *func_name,
int line_num, bool eol, const char* fmt, ...)
FUNC_ATTR_UNUSED
{ {
if (log_level < MIN_LOG_LEVEL) { if (log_level < MIN_LOG_LEVEL) {
return false; return false;
@ -112,8 +116,8 @@ bool do_log(int log_level, const char *func_name, int line_num, bool eol,
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
ret = v_do_log_to_file(log_file, log_level, func_name, line_num, eol, ret = v_do_log_to_file(log_file, log_level, context, func_name, line_num,
fmt, args); eol, fmt, args);
va_end(args); va_end(args);
if (log_file != stderr && log_file != stdout) { if (log_file != stderr && log_file != stdout) {
@ -151,7 +155,7 @@ FILE *open_log_file(void)
static bool opening_log_file = false; static bool opening_log_file = false;
// check if it's a recursive call // check if it's a recursive call
if (opening_log_file) { if (opening_log_file) {
do_log_to_file(stderr, ERROR_LOG_LEVEL, __func__, __LINE__, true, do_log_to_file(stderr, ERROR_LOG_LEVEL, NULL, __func__, __LINE__, true,
"Cannot LOG() recursively."); "Cannot LOG() recursively.");
return stderr; return stderr;
} }
@ -171,7 +175,7 @@ FILE *open_log_file(void)
// - LOG() is called before early_init() // - LOG() is called before early_init()
// - Directory does not exist // - Directory does not exist
// - File is not writable // - File is not writable
do_log_to_file(stderr, ERROR_LOG_LEVEL, __func__, __LINE__, true, do_log_to_file(stderr, ERROR_LOG_LEVEL, NULL, __func__, __LINE__, true,
"Logging to stderr, failed to open $" LOG_FILE_ENV ": %s", "Logging to stderr, failed to open $" LOG_FILE_ENV ": %s",
log_file_path); log_file_path);
return stderr; return stderr;
@ -201,7 +205,7 @@ void log_callstack_to_file(FILE *log_file, const char *const func_name,
// Now we have a command string like: // Now we have a command string like:
// addr2line -e /path/to/exe -f -p 0x123 0x456 ... // addr2line -e /path/to/exe -f -p 0x123 0x456 ...
do_log_to_file(log_file, DEBUG_LOG_LEVEL, func_name, line_num, true, do_log_to_file(log_file, DEBUG_LOG_LEVEL, NULL, func_name, line_num, true,
"trace:"); "trace:");
FILE *fp = popen(cmdbuf, "r"); FILE *fp = popen(cmdbuf, "r");
char linebuf[IOSIZE]; char linebuf[IOSIZE];
@ -230,22 +234,23 @@ end:
} }
#endif #endif
static bool do_log_to_file(FILE *log_file, int log_level, static bool do_log_to_file(FILE *log_file, int log_level, const char *context,
const char *func_name, int line_num, bool eol, const char *func_name, int line_num, bool eol,
const char* fmt, ...) const char* fmt, ...)
{ {
va_list args; va_list args;
va_start(args, fmt); va_start(args, fmt);
bool ret = v_do_log_to_file(log_file, log_level, func_name, line_num, eol, bool ret = v_do_log_to_file(log_file, log_level, context, func_name,
fmt, args); line_num, eol, fmt, args);
va_end(args); va_end(args);
return ret; return ret;
} }
static bool v_do_log_to_file(FILE *log_file, int log_level, static bool v_do_log_to_file(FILE *log_file, int log_level,
const char *func_name, int line_num, bool eol, const char *context, const char *func_name,
const char* fmt, va_list args) int line_num, bool eol, const char* fmt,
va_list args)
{ {
static const char *log_levels[] = { static const char *log_levels[] = {
[DEBUG_LOG_LEVEL] = "DEBUG", [DEBUG_LOG_LEVEL] = "DEBUG",
@ -268,8 +273,15 @@ static bool v_do_log_to_file(FILE *log_file, int log_level,
// print the log message prefixed by the current timestamp and pid // print the log message prefixed by the current timestamp and pid
int64_t pid = os_get_pid(); int64_t pid = os_get_pid();
if (fprintf(log_file, "%s %s %" PRId64 "/%s:%d: ", date_time, int rv = (line_num == -1 || func_name == NULL)
log_levels[log_level], pid, func_name, line_num) < 0) { ? fprintf(log_file, "%s %s %" PRId64 " %s", date_time,
log_levels[log_level], pid,
(context == NULL ? "?:" : context))
: fprintf(log_file, "%s %s %" PRId64 " %s%s:%d: ", date_time,
log_levels[log_level], pid,
(context == NULL ? "" : context),
func_name, line_num);
if (rv < 0) {
return false; return false;
} }
if (vfprintf(log_file, fmt, args) < 0) { if (vfprintf(log_file, fmt, args) < 0) {

View File

@ -22,42 +22,42 @@
# define MIN_LOG_LEVEL INFO_LOG_LEVEL # define MIN_LOG_LEVEL INFO_LOG_LEVEL
#endif #endif
#define LOG(level, ...) do_log((level), __func__, __LINE__, true, \ #define LOG(level, ...) do_log((level), NULL, __func__, __LINE__, true, \
__VA_ARGS__) __VA_ARGS__)
#if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL #if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL
# undef DLOG # undef DLOG
# undef DLOGN # undef DLOGN
# define DLOG(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, true, \ # define DLOG(...) do_log(DEBUG_LOG_LEVEL, NULL, __func__, __LINE__, true, \
__VA_ARGS__) __VA_ARGS__)
# define DLOGN(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, false, \ # define DLOGN(...) do_log(DEBUG_LOG_LEVEL, NULL, __func__, __LINE__, false, \
__VA_ARGS__) __VA_ARGS__)
#endif #endif
#if MIN_LOG_LEVEL <= INFO_LOG_LEVEL #if MIN_LOG_LEVEL <= INFO_LOG_LEVEL
# undef ILOG # undef ILOG
# undef ILOGN # undef ILOGN
# define ILOG(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, true, \ # define ILOG(...) do_log(INFO_LOG_LEVEL, NULL, __func__, __LINE__, true, \
__VA_ARGS__) __VA_ARGS__)
# define ILOGN(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, false, \ # define ILOGN(...) do_log(INFO_LOG_LEVEL, NULL, __func__, __LINE__, false, \
__VA_ARGS__) __VA_ARGS__)
#endif #endif
#if MIN_LOG_LEVEL <= WARN_LOG_LEVEL #if MIN_LOG_LEVEL <= WARN_LOG_LEVEL
# undef WLOG # undef WLOG
# undef WLOGN # undef WLOGN
# define WLOG(...) do_log(WARN_LOG_LEVEL, __func__, __LINE__, true, \ # define WLOG(...) do_log(WARN_LOG_LEVEL, NULL, __func__, __LINE__, true, \
__VA_ARGS__) __VA_ARGS__)
# define WLOGN(...) do_log(WARN_LOG_LEVEL, __func__, __LINE__, false, \ # define WLOGN(...) do_log(WARN_LOG_LEVEL, NULL, __func__, __LINE__, false, \
__VA_ARGS__) __VA_ARGS__)
#endif #endif
#if MIN_LOG_LEVEL <= ERROR_LOG_LEVEL #if MIN_LOG_LEVEL <= ERROR_LOG_LEVEL
# undef ELOG # undef ELOG
# undef ELOGN # undef ELOGN
# define ELOG(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, true, \ # define ELOG(...) do_log(ERROR_LOG_LEVEL, NULL, __func__, __LINE__, true, \
__VA_ARGS__) __VA_ARGS__)
# define ELOGN(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, false, \ # define ELOGN(...) do_log(ERROR_LOG_LEVEL, NULL, __func__, __LINE__, false, \
__VA_ARGS__) __VA_ARGS__)
#endif #endif

View File

@ -71,10 +71,10 @@ static char uilog_last_event[1024] = { 0 };
uilog_seen++; \ uilog_seen++; \
} else { \ } else { \
if (uilog_seen > 0) { \ if (uilog_seen > 0) { \
do_log(DEBUG_LOG_LEVEL, "ui", 0, true, \ do_log(DEBUG_LOG_LEVEL, "UI: ", NULL, -1, true, \
"%s (+%zu times...)", uilog_last_event, uilog_seen); \ "%s (+%zu times...)", uilog_last_event, uilog_seen); \
} \ } \
DLOG("ui: " STR(funname)); \ do_log(DEBUG_LOG_LEVEL, "UI: ", NULL, -1, true, STR(funname)); \
uilog_seen = 0; \ uilog_seen = 0; \
xstrlcpy(uilog_last_event, STR(funname), sizeof(uilog_last_event)); \ xstrlcpy(uilog_last_event, STR(funname), sizeof(uilog_last_event)); \
} \ } \