diff options
Diffstat (limited to 'src/nvim/log.c')
| -rw-r--r-- | src/nvim/log.c | 206 |
1 files changed, 160 insertions, 46 deletions
diff --git a/src/nvim/log.c b/src/nvim/log.c index bbb4dfb944..7bfe5c4089 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -1,23 +1,23 @@ +// This is an open source non-commercial project. Dear PVS-Studio, please check +// it. PVS-Studio Static Code Analyzer for C, C++ and C#: http://www.viva64.com + #include <assert.h> #include <inttypes.h> #include <stdarg.h> #include <stdbool.h> #include <stdint.h> #include <stdio.h> +#include <uv.h> #include "nvim/log.h" #include "nvim/types.h" #include "nvim/os/os.h" #include "nvim/os/time.h" -/// First location of the log file used by log_path_init() -#define USR_LOG_FILE "$NVIM_LOG_FILE" - -/// Fall back location of the log file used by log_path_init() -#define USR_LOG_FILE_2 "$HOME" _PATHSEPSTR ".nvimlog" +#define LOG_FILE_ENV "NVIM_LOG_FILE" -/// Cached location of the log file set by log_path_init() -static char expanded_log_file_path[MAXPATHL + 1] = { 0 }; +/// Cached location of the expanded log file path decided by log_path_init(). +static char log_file_path[MAXPATHL + 1] = { 0 }; static uv_mutex_t mutex; @@ -25,31 +25,57 @@ static uv_mutex_t mutex; # include "log.c.generated.h" #endif -/// Initialize path to log file +#ifdef HAVE_EXECINFO_BACKTRACE +# include <execinfo.h> +#endif + +static bool log_try_create(char *fname) +{ + if (fname == NULL || fname[0] == '\0') { + return false; + } + FILE *log_file = fopen(fname, "a"); + if (log_file == NULL) { + return false; + } + fclose(log_file); + return true; +} + +/// Initializes path to log file. Sets $NVIM_LOG_FILE if empty. /// -/// Tries to use #USR_LOG_FILE, then falls back #USR_LOG_FILE_2. Path to log +/// Tries $NVIM_LOG_FILE, or falls back to $XDG_DATA_HOME/nvim/log. Path to log /// file is cached, so only the first call has effect, unless first call was not -/// successful. To make initialization not succeed either a bug in expand_env() -/// is needed or both `$NVIM_LOG_FILE` and `$HOME` environment variables -/// undefined. +/// successful. Failed initialization indicates either a bug in expand_env() +/// or both $NVIM_LOG_FILE and $HOME environment variables are undefined. /// /// @return true if path was initialized, false otherwise. static bool log_path_init(void) { - if (expanded_log_file_path[0]) { + if (log_file_path[0]) { return true; } - expand_env((char_u *)USR_LOG_FILE, (char_u *)expanded_log_file_path, - sizeof(expanded_log_file_path) - 1); - // if the log file path expansion failed then fall back to stderr - if (strcmp(USR_LOG_FILE, expanded_log_file_path) == 0) { - memset(expanded_log_file_path, 0, sizeof(expanded_log_file_path)); - expand_env((char_u *)USR_LOG_FILE_2, (char_u *)expanded_log_file_path, - sizeof(expanded_log_file_path) - 1); - if (strcmp(USR_LOG_FILE_2, expanded_log_file_path) == 0) { - memset(expanded_log_file_path, 0, sizeof(expanded_log_file_path)); + size_t size = sizeof(log_file_path); + expand_env((char_u *)"$" LOG_FILE_ENV, (char_u *)log_file_path, + (int)size - 1); + if (strequal("$" LOG_FILE_ENV, log_file_path) + || log_file_path[0] == '\0' + || os_isdir((char_u *)log_file_path) + || !log_try_create(log_file_path)) { + // Invalid $NVIM_LOG_FILE or failed to expand; fall back to default. + char *defaultpath = stdpaths_user_data_subpath("log", 0, true); + size_t len = xstrlcpy(log_file_path, defaultpath, size); + xfree(defaultpath); + // Fall back to .nvimlog + if (len >= size || !log_try_create(log_file_path)) { + len = xstrlcpy(log_file_path, ".nvimlog", size); + } + // Fall back to stderr + if (len >= size || !log_try_create(log_file_path)) { + log_file_path[0] = '\0'; return false; } + os_setenv(LOG_FILE_ENV, log_file_path, true); } return true; } @@ -69,9 +95,17 @@ void log_unlock(void) uv_mutex_unlock(&mutex); } -bool do_log(int log_level, const char *func_name, int line_num, bool eol, - const char* fmt, ...) FUNC_ATTR_UNUSED +/// @param context description of a shared context or subsystem +/// @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) { + return false; + } + log_lock(); bool ret = false; FILE *log_file = open_log_file(); @@ -82,8 +116,8 @@ bool do_log(int log_level, const char *func_name, int line_num, bool eol, va_list args; va_start(args, fmt); - ret = v_do_log_to_file(log_file, log_level, func_name, line_num, eol, - fmt, args); + ret = v_do_log_to_file(log_file, log_level, context, func_name, line_num, + eol, fmt, args); va_end(args); if (log_file != stderr && log_file != stdout) { @@ -94,26 +128,42 @@ end: return ret; } +void log_uv_handles(void *loop) +{ + uv_loop_t *l = loop; + log_lock(); + FILE *log_file = open_log_file(); + + if (log_file == NULL) { + goto end; + } + + uv_print_all_handles(l, log_file); + + if (log_file != stderr && log_file != stdout) { + fclose(log_file); + } +end: + log_unlock(); +} + /// Open the log file for appending. /// -/// @return The FILE* specified by the USR_LOG_FILE path or stderr in case of -/// error +/// @return FILE* decided by log_path_init() or stderr in case of error FILE *open_log_file(void) { static bool opening_log_file = false; - // check if it's a recursive call if (opening_log_file) { - do_log_to_file(stderr, ERROR_LOG_LEVEL, __func__, __LINE__, true, - "Trying to LOG() recursively! Please fix it."); + do_log_to_file(stderr, ERROR_LOG_LEVEL, NULL, __func__, __LINE__, true, + "Cannot LOG() recursively."); return stderr; } - // expand USR_LOG_FILE if needed and open the file FILE *log_file = NULL; opening_log_file = true; if (log_path_init()) { - log_file = fopen(expanded_log_file_path, "a"); + log_file = fopen(log_file_path, "a"); } opening_log_file = false; @@ -121,35 +171,92 @@ FILE *open_log_file(void) return log_file; } - do_log_to_file(stderr, ERROR_LOG_LEVEL, __func__, __LINE__, true, - "Couldn't open USR_LOG_FILE, logging to stderr! This may be " - "caused by attempting to LOG() before initialization " - "functions are called (e.g. init_homedir())."); + // May happen if: + // - LOG() is called before early_init() + // - Directory does not exist + // - File is not writable + do_log_to_file(stderr, ERROR_LOG_LEVEL, NULL, __func__, __LINE__, true, + "Logging to stderr, failed to open $" LOG_FILE_ENV ": %s", + log_file_path); return stderr; } -static bool do_log_to_file(FILE *log_file, int log_level, +#ifdef HAVE_EXECINFO_BACKTRACE +void log_callstack_to_file(FILE *log_file, const char *const func_name, + const int line_num) +{ + void *trace[100]; + int trace_size = backtrace(trace, ARRAY_SIZE(trace)); + + char exepath[MAXPATHL] = { 0 }; + size_t exepathlen = MAXPATHL; + if (os_exepath(exepath, &exepathlen) != 0) { + abort(); + } + assert(24 + exepathlen < IOSIZE); // Must fit in `cmdbuf` below. + + char cmdbuf[IOSIZE + (20 * ARRAY_SIZE(trace))]; + snprintf(cmdbuf, sizeof(cmdbuf), "addr2line -e %s -f -p", exepath); + for (int i = 1; i < trace_size; i++) { + char buf[20]; // 64-bit pointer 0xNNNNNNNNNNNNNNNN with leading space. + snprintf(buf, sizeof(buf), " %p", trace[i]); + xstrlcat(cmdbuf, buf, sizeof(cmdbuf)); + } + // Now we have a command string like: + // addr2line -e /path/to/exe -f -p 0x123 0x456 ... + + do_log_to_file(log_file, DEBUG_LOG_LEVEL, NULL, func_name, line_num, true, + "trace:"); + FILE *fp = popen(cmdbuf, "r"); + char linebuf[IOSIZE]; + while (fgets(linebuf, sizeof(linebuf) - 1, fp) != NULL) { + fprintf(log_file, " %s", linebuf); + } + pclose(fp); + + if (log_file != stderr && log_file != stdout) { + fclose(log_file); + } +} + +void log_callstack(const char *const func_name, const int line_num) +{ + log_lock(); + FILE *log_file = open_log_file(); + if (log_file == NULL) { + goto end; + } + + log_callstack_to_file(log_file, func_name, line_num); + +end: + log_unlock(); +} +#endif + +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* fmt, ...) { va_list args; va_start(args, fmt); - bool ret = v_do_log_to_file(log_file, log_level, func_name, line_num, eol, - fmt, args); + bool ret = v_do_log_to_file(log_file, log_level, context, func_name, + line_num, eol, fmt, args); va_end(args); return ret; } static bool v_do_log_to_file(FILE *log_file, int log_level, - const char *func_name, int line_num, bool eol, - const char* fmt, va_list args) + const char *context, const char *func_name, + int line_num, bool eol, const char *fmt, + va_list args) { static const char *log_levels[] = { [DEBUG_LOG_LEVEL] = "DEBUG", [INFO_LOG_LEVEL] = "INFO ", - [WARNING_LOG_LEVEL] = "WARN ", - [ERROR_LOG_LEVEL] = "ERROR" + [WARN_LOG_LEVEL] = "WARN ", + [ERROR_LOG_LEVEL] = "ERROR", }; assert(log_level >= DEBUG_LOG_LEVEL && log_level <= ERROR_LOG_LEVEL); @@ -166,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 int64_t pid = os_get_pid(); - if (fprintf(log_file, "%s %s %" PRId64 "/%s:%d: ", date_time, - log_levels[log_level], pid, func_name, line_num) < 0) { + int rv = (line_num == -1 || func_name == NULL) + ? 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; } if (vfprintf(log_file, fmt, args) < 0) { |