diff options
author | Justin M. Keyes <justinkz@gmail.com> | 2017-06-07 23:19:02 +0200 |
---|---|---|
committer | GitHub <noreply@github.com> | 2017-06-07 23:19:02 +0200 |
commit | 16cce1ac17456e3758f95af6ce7289bade3bb285 (patch) | |
tree | 1e5bc9c076e6a49dcc750cb686c45a0e371b3a31 | |
parent | d3d0c9a7b11cad3f277f732dee6c782d1d911b48 (diff) | |
parent | bc025ab117c92418f890085dc13f26cb7c976772 (diff) | |
download | rneovim-16cce1ac17456e3758f95af6ce7289bade3bb285.tar.gz rneovim-16cce1ac17456e3758f95af6ce7289bade3bb285.tar.bz2 rneovim-16cce1ac17456e3758f95af6ce7289bade3bb285.zip |
Merge #6827 'Always enable logging'
-rw-r--r-- | .travis.yml | 5 | ||||
-rw-r--r-- | CMakeLists.txt | 18 | ||||
-rw-r--r-- | CONTRIBUTING.md | 24 | ||||
-rw-r--r-- | ci/common/suite.sh | 7 | ||||
-rw-r--r-- | cmake/RunTests.cmake | 4 | ||||
-rw-r--r-- | contrib/local.mk.example | 5 | ||||
-rw-r--r-- | runtime/doc/starting.txt | 63 | ||||
-rw-r--r-- | src/nvim/cursor_shape.c | 2 | ||||
-rw-r--r-- | src/nvim/eval.c | 2 | ||||
-rw-r--r-- | src/nvim/event/loop.c | 21 | ||||
-rw-r--r-- | src/nvim/garray.h | 2 | ||||
-rw-r--r-- | src/nvim/log.c | 106 | ||||
-rw-r--r-- | src/nvim/log.h | 74 | ||||
-rw-r--r-- | src/nvim/main.c | 7 | ||||
-rw-r--r-- | src/nvim/msgpack_rpc/channel.c | 12 | ||||
-rw-r--r-- | src/nvim/msgpack_rpc/server.c | 4 | ||||
-rw-r--r-- | src/nvim/os/shell.c | 2 | ||||
-rw-r--r-- | src/nvim/os_unix.c | 4 | ||||
-rw-r--r-- | src/nvim/testdir/runtest.vim | 2 | ||||
-rw-r--r-- | src/nvim/testdir/shared.vim | 2 | ||||
-rw-r--r-- | test/README.md | 2 | ||||
-rw-r--r-- | test/functional/helpers.lua | 2 | ||||
-rw-r--r-- | test/functional/options/defaults_spec.lua | 52 |
23 files changed, 269 insertions, 153 deletions
diff --git a/.travis.yml b/.travis.yml index 8ca6f58fec..5b2bbe7946 100644 --- a/.travis.yml +++ b/.travis.yml @@ -21,14 +21,15 @@ env: - INSTALL_PREFIX="$HOME/nvim-install" # Log directory for Clang sanitizers and Valgrind. - LOG_DIR="$BUILD_DIR/log" + # Nvim log file. + - NVIM_LOG_FILE="$BUILD_DIR/.nvimlog" # Default CMake flags. - CMAKE_FLAGS="-DTRAVIS_CI_BUILD=ON -DCMAKE_BUILD_TYPE=Debug -DCMAKE_INSTALL_PREFIX:PATH=$INSTALL_PREFIX -DBUSTED_OUTPUT_TYPE=nvim -DDEPS_PREFIX=$DEPS_BUILD_DIR/usr - -DMIN_LOG_LEVEL=3 - -DDISABLE_LOG=1" + -DMIN_LOG_LEVEL=3" - DEPS_CMAKE_FLAGS="-DDEPS_DOWNLOAD_DIR:PATH=$DEPS_DOWNLOAD_DIR" # Additional CMake flags for 32-bit builds. - CMAKE_FLAGS_32BIT="-DCMAKE_SYSTEM_LIBRARY_PATH=/lib32:/usr/lib32:/usr/local/lib32 diff --git a/CMakeLists.txt b/CMakeLists.txt index 117519230f..11afefe4cd 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -96,15 +96,15 @@ if(CMAKE_C_FLAGS_RELEASE MATCHES "-O3") string(REPLACE "-O3" "-O2" CMAKE_C_FLAGS_RELEASE "${CMAKE_C_FLAGS_RELEASE}") endif() -# Disable logging for release-type builds. -if(NOT CMAKE_C_FLAGS_RELEASE MATCHES DDISABLE_LOG) - set(CMAKE_C_FLAGS_RELEASE "${CMAKE_C_FLAGS_RELEASE} -DDISABLE_LOG") +# Minimize logging for release-type builds. +if(NOT CMAKE_C_FLAGS_RELEASE MATCHES DMIN_LOG_LEVEL) + set(CMAKE_C_FLAGS_RELEASE "${CMAKE_C_FLAGS_RELEASE} -DMIN_LOG_LEVEL=3") endif() -if(NOT CMAKE_C_FLAGS_MINSIZEREL MATCHES DDISABLE_LOG) - set(CMAKE_C_FLAGS_MINSIZEREL "${CMAKE_C_FLAGS_MINSIZEREL} -DDISABLE_LOG") +if(NOT CMAKE_C_FLAGS_MINSIZEREL MATCHES DMIN_LOG_LEVEL) + set(CMAKE_C_FLAGS_MINSIZEREL "${CMAKE_C_FLAGS_MINSIZEREL} -DMIN_LOG_LEVEL=3") endif() -if(NOT CMAKE_C_FLAGS_RELWITHDEBINFO MATCHES DDISABLE_LOG) - set(CMAKE_C_FLAGS_RELWITHDEBINFO "${CMAKE_C_FLAGS_RELWITHDEBINFO} -DDISABLE_LOG") +if(NOT CMAKE_C_FLAGS_RELWITHDEBINFO MATCHES DMIN_LOG_LEVEL) + set(CMAKE_C_FLAGS_RELWITHDEBINFO "${CMAKE_C_FLAGS_RELWITHDEBINFO} -DMIN_LOG_LEVEL=3") endif() # Enable assertions for RelWithDebInfo. @@ -463,11 +463,11 @@ install_helper( # MIN_LOG_LEVEL for log.h if(DEFINED MIN_LOG_LEVEL) if(NOT MIN_LOG_LEVEL MATCHES "^[0-3]$") - message(FATAL_ERROR "MIN_LOG_LEVEL must be a number 0-3") + message(FATAL_ERROR "invalid MIN_LOG_LEVEL: " ${MIN_LOG_LEVEL}) endif() message(STATUS "MIN_LOG_LEVEL set to ${MIN_LOG_LEVEL}") else() - message(STATUS "MIN_LOG_LEVEL not specified, defaulting to INFO(1)") + message(STATUS "MIN_LOG_LEVEL not specified, defaulting to 1 (INFO)") endif() # Go down the tree. diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 072da69b85..8580e8ef39 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -6,7 +6,7 @@ Getting started If you want to help but don't know where to start, here are some low-risk/isolated tasks: -- Merge a [Vim patch]. +- [Merge a Vim patch]. - Try a [complexity:low] issue. - Fix bugs found by [clang scan-build](#clang-scan-build), [coverity](#coverity), and [PVS](#pvs-studio). @@ -23,18 +23,16 @@ Reporting problems - Check the [**FAQ**][wiki-faq]. - Search [existing issues][github-issues] (including closed!) - Update Neovim to the latest version to see if your problem persists. -- If you're using a plugin manager, comment out your plugins, then add them back - in one by one, to narrow down the cause of the issue. -- Crash reports which include a stacktrace are 10x more valuable. -- [Bisecting][git-bisect] to the cause of a regression often leads to an - immediate fix. +- Disable plugins incrementally, to narrow down the cause of the issue. +- When reporting a crash, include a stacktrace. +- [Bisect][git-bisect] to the cause of a regression, if you are able. This is _extremely_ helpful. +- Check `$NVIM_LOG_FILE`, if it exists. Pull requests ("PRs") --------------------- - To avoid duplicate work, create a `[WIP]` pull request as soon as possible. -- Avoid cosmetic changes to unrelated files in the same commit: noise makes - reviews take longer. +- Avoid cosmetic changes to unrelated files in the same commit. - Use a [feature branch][git-feature-branch] instead of the master branch. - Use a **rebase workflow** for small PRs. - After addressing review comments, it's fine to rebase and force-push. @@ -87,10 +85,11 @@ the VCS/git logs more valuable. ### Automated builds (CI) -Each pull request must pass the automated builds ([travis CI] and [quickbuild]). +Each pull request must pass the automated builds on [travis CI], [quickbuild] +and [AppVeyor]. -- CI builds are compiled with [`-Werror`][gcc-warnings], so if your PR - introduces any compiler warnings, the build will fail. +- CI builds are compiled with [`-Werror`][gcc-warnings], so compiler warnings + will fail the build. - If any tests fail, the build will fail. See [Building Neovim#running-tests][wiki-run-tests] to run tests locally. Passing locally doesn't guarantee passing the CI build, because of the @@ -173,6 +172,7 @@ as context, use the `-W` argument as well. [3174]: https://github.com/neovim/neovim/issues/3174 [travis CI]: https://travis-ci.org/neovim/neovim [quickbuild]: http://neovim-qb.szakmeister.net/dashboard -[Vim patch]: https://github.com/neovim/neovim/wiki/Merging-patches-from-upstream-Vim +[AppVeyor]: https://ci.appveyor.com/project/neovim/neovim +[Merge a Vim patch]: https://github.com/neovim/neovim/wiki/Merging-patches-from-upstream-Vim [clang-scan]: https://neovim.io/doc/reports/clang/ [complexity:low]: https://github.com/neovim/neovim/issues?q=is%3Aopen+is%3Aissue+label%3Acomplexity%3Alow diff --git a/ci/common/suite.sh b/ci/common/suite.sh index 8feb642547..d3fbcd1eda 100644 --- a/ci/common/suite.sh +++ b/ci/common/suite.sh @@ -39,6 +39,13 @@ enter_suite() { exit_suite() { set +x + if test -f "$NVIM_LOG_FILE" ; then + printf "===============================================================================\n" + printf "NVIM_LOG_FILE: $NVIM_LOG_FILE\n" + cat "$NVIM_LOG_FILE" 2>/dev/null || printf '(empty)' + printf "\n" + rm -rf "$NVIM_LOG_FILE" + fi travis_fold end "${NVIM_TEST_CURRENT_SUITE}" if test $FAILED -ne 0 ; then echo "Suite ${NVIM_TEST_CURRENT_SUITE} failed, summary:" diff --git a/cmake/RunTests.cmake b/cmake/RunTests.cmake index bd7b630708..5f818cc9ad 100644 --- a/cmake/RunTests.cmake +++ b/cmake/RunTests.cmake @@ -3,6 +3,10 @@ set(ENV{NVIM_RPLUGIN_MANIFEST} ${WORKING_DIR}/Xtest_rplugin_manifest) set(ENV{XDG_CONFIG_HOME} ${WORKING_DIR}/Xtest_xdg/config) set(ENV{XDG_DATA_HOME} ${WORKING_DIR}/Xtest_xdg/share) +if(NOT DEFINED ENV{NVIM_LOG_FILE}) + set(ENV{NVIM_LOG_FILE} ${WORKING_DIR}/.nvimlog) +endif() + if(NVIM_PRG) set(ENV{NVIM_PRG} "${NVIM_PRG}") endif() diff --git a/contrib/local.mk.example b/contrib/local.mk.example index 04f21131b8..cadb9cf4b2 100644 --- a/contrib/local.mk.example +++ b/contrib/local.mk.example @@ -31,9 +31,8 @@ # # CMAKE_BUILD_TYPE := Debug -# By default, nvim's log level is INFO (1) (unless CMAKE_BUILD_TYPE is -# "Release", in which case logging is disabled). -# The log level must be a number DEBUG (0), INFO (1), WARNING (2) or ERROR (3). +# The default log level is 1 (INFO) (unless CMAKE_BUILD_TYPE is "Release"). +# Log levels: 0 (DEBUG), 1 (INFO), 2 (WARNING), 3 (ERROR) # CMAKE_EXTRA_FLAGS += -DMIN_LOG_LEVEL=1 # By default, nvim uses bundled versions of its required third-party diff --git a/runtime/doc/starting.txt b/runtime/doc/starting.txt index 4b3f894cf7..8581bcfb72 100644 --- a/runtime/doc/starting.txt +++ b/runtime/doc/starting.txt @@ -1366,39 +1366,38 @@ file when reading and include: complete MessagePack object. ============================================================================== -9. Base Directories *base-directories* *xdg* +9. Standard Paths -Nvim conforms to the XDG Base Directory Specification for application -configuration and data file locations. This just means Nvim looks for some -optional settings and uses them if they exist, otherwise defaults are chosen. -https://specifications.freedesktop.org/basedir-spec/basedir-spec-latest.html - -CONFIGURATION DIRECTORY *$XDG_CONFIG_HOME* - - Base directory default: - Unix: ~/.config - Windows: ~/AppData/Local - - Nvim directory: - Unix: ~/.config/nvim/ - Windows: ~/AppData/Local/nvim/ - -DATA DIRECTORY *$XDG_DATA_HOME* +Nvim stores configuration and data in standard locations. Plugins are strongly +encouraged to follow this pattern also. - Base directory default: - Unix: ~/.local/share - Windows: ~/AppData/Local - - Nvim directory: - Unix: ~/.local/share/nvim/ - Windows: ~/AppData/Local/nvim-data/ - -Note on Windows the configuration and data directory defaults are the same -(for lack of an alternative), but the sub-directory for data is named -"nvim-data" to separate it from the configuration sub-directory "nvim". - -Throughout other sections of the user manual, the defaults are used as generic -placeholders, e.g. where "~/.config" is mentioned it should be understood to -mean "$XDG_CONFIG_HOME or ~/.config". + *base-directories* *xdg* +The "base" (root) directories conform to the XDG Base Directory Specification. +https://specifications.freedesktop.org/basedir-spec/basedir-spec-latest.html +The $XDG_CONFIG_HOME and $XDG_DATA_HOME environment variables are used if they +exist, otherwise default values (listed below) are used. + +Note: Throughout the user manual these defaults are used as placeholders, e.g. +"~/.config" is understood to mean "$XDG_CONFIG_HOME or ~/.config". + +CONFIG DIRECTORY *$XDG_CONFIG_HOME* + Base Nvim ~ +Unix: ~/.config ~/.config/nvim +Windows: ~/AppData/Local ~/AppData/Local/nvim + +DATA DIRECTORY *$XDG_DATA_HOME* + Base Nvim ~ +Unix: ~/.local/share ~/.local/share/nvim +Windows: ~/AppData/Local ~/AppData/Local/nvim-data + +STANDARD PATHS *standard-path* + + *$NVIM_LOG_FILE* +Besides 'debug' and 'verbose', Nvim has a low-level "log of last resort" that +is written directly to the filesystem. This log may also be used by plugins or +RPC clients for debugging. $NVIM_LOG_FILE contains the log file path: > + :echo $NVIM_LOG_FILE +Usually the file is ~/.local/share/nvim/log unless that path is inaccessible +or if $NVIM_LOG_FILE was set before |startup|. vim:tw=78:ts=8:ft=help:norl: diff --git a/src/nvim/cursor_shape.c b/src/nvim/cursor_shape.c index e302d5aa4c..97fc3a3ca3 100644 --- a/src/nvim/cursor_shape.c +++ b/src/nvim/cursor_shape.c @@ -260,7 +260,7 @@ int cursor_mode_str2int(const char *mode) return current_mode; } } - ELOG("Unknown mode %s", mode); + WLOG("Unknown mode %s", mode); return -1; } diff --git a/src/nvim/eval.c b/src/nvim/eval.c index 94916e3e3c..baa61a26bc 100644 --- a/src/nvim/eval.c +++ b/src/nvim/eval.c @@ -14362,7 +14362,7 @@ static void f_serverstart(typval_T *argvars, typval_T *rettv, FunPtr fptr) if (result != 0) { EMSG2("Failed to start server: %s", - result > 0 ? "Unknonwn system error" : uv_strerror(result)); + result > 0 ? "Unknown system error" : uv_strerror(result)); return; } diff --git a/src/nvim/event/loop.c b/src/nvim/event/loop.c index c709ce9a1c..25701a1621 100644 --- a/src/nvim/event/loop.c +++ b/src/nvim/event/loop.c @@ -8,6 +8,7 @@ #include "nvim/event/loop.h" #include "nvim/event/process.h" +#include "nvim/log.h" #ifdef INCLUDE_GENERATED_DECLARATIONS # include "event/loop.c.generated.h" @@ -78,20 +79,34 @@ void loop_on_put(MultiQueue *queue, void *data) uv_stop(&loop->uv); } -void loop_close(Loop *loop, bool wait) +/// @returns false if the loop could not be closed gracefully +bool loop_close(Loop *loop, bool wait) { + bool rv = true; uv_mutex_destroy(&loop->mutex); uv_close((uv_handle_t *)&loop->children_watcher, NULL); uv_close((uv_handle_t *)&loop->children_kill_timer, NULL); uv_close((uv_handle_t *)&loop->poll_timer, NULL); uv_close((uv_handle_t *)&loop->async, NULL); - do { + uint64_t start = wait ? os_hrtime() : 0; + while (true) { uv_run(&loop->uv, wait ? UV_RUN_DEFAULT : UV_RUN_NOWAIT); - } while (uv_loop_close(&loop->uv) && wait); + if (!uv_loop_close(&loop->uv) || !wait) { + break; + } + if (os_hrtime() - start >= 2 * 1000000000) { + // Some libuv resource was not correctly deref'd. Log and bail. + rv = false; + ELOG("uv_loop_close() hang?"); + log_uv_handles(&loop->uv); + break; + } + } multiqueue_free(loop->fast_events); multiqueue_free(loop->thread_events); multiqueue_free(loop->events); kl_destroy(WatcherPtr, loop->children); + return rv; } void loop_purge(Loop *loop) diff --git a/src/nvim/garray.h b/src/nvim/garray.h index 5d7806bbfa..94e1b61671 100644 --- a/src/nvim/garray.h +++ b/src/nvim/garray.h @@ -37,7 +37,7 @@ typedef struct growarray { static inline void *ga_append_via_ptr(garray_T *gap, size_t item_size) { if ((int)item_size != gap->ga_itemsize) { - ELOG("wrong item size in garray(%d), should be %d", item_size); + WLOG("wrong item size (%d), should be %d", item_size, gap->ga_itemsize); } ga_grow(gap, 1); return ((char *)gap->ga_data) + (item_size * (size_t)gap->ga_len++); diff --git a/src/nvim/log.c b/src/nvim/log.c index d059e28d5d..f1dbe61dda 100644 --- a/src/nvim/log.c +++ b/src/nvim/log.c @@ -7,20 +7,17 @@ #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" +#define LOG_FILE_ENV "NVIM_LOG_FILE" -/// Fall back location of the log file used by log_path_init() -#define USR_LOG_FILE_2 "$HOME" _PATHSEPSTR ".nvimlog" - -/// 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; @@ -28,31 +25,53 @@ static uv_mutex_t mutex; # include "log.c.generated.h" #endif -/// Initialize path to log file +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; } @@ -75,6 +94,10 @@ void log_unlock(void) bool do_log(int log_level, 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(); @@ -97,26 +120,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."); + "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; @@ -124,10 +163,13 @@ FILE *open_log_file(void) return log_file; } + // 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, __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())."); + "Logging to stderr, failed to open $" LOG_FILE_ENV ": %s", + log_file_path); return stderr; } @@ -152,7 +194,7 @@ static bool v_do_log_to_file(FILE *log_file, int log_level, [DEBUG_LOG_LEVEL] = "DEBUG", [INFO_LOG_LEVEL] = "INFO ", [WARNING_LOG_LEVEL] = "WARN ", - [ERROR_LOG_LEVEL] = "ERROR" + [ERROR_LOG_LEVEL] = "ERROR", }; assert(log_level >= DEBUG_LOG_LEVEL && log_level <= ERROR_LOG_LEVEL); diff --git a/src/nvim/log.h b/src/nvim/log.h index 32b7276f14..221f0bbaf6 100644 --- a/src/nvim/log.h +++ b/src/nvim/log.h @@ -18,55 +18,47 @@ #define ELOG(...) #define ELOGN(...) -// Logging is disabled if NDEBUG or DISABLE_LOG is defined. -#if !defined(DISABLE_LOG) && defined(NDEBUG) -# define DISABLE_LOG -#endif - -// MIN_LOG_LEVEL can be defined during compilation to adjust the desired level -// of logging. INFO_LOG_LEVEL is used by default. #ifndef MIN_LOG_LEVEL # define MIN_LOG_LEVEL INFO_LOG_LEVEL #endif -#ifndef DISABLE_LOG - -# if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL -# undef DLOG -# undef DLOGN -# define DLOG(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, true, \ - __VA_ARGS__) -# define DLOGN(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, false, \ - __VA_ARGS__) -# endif +#define LOG(level, ...) do_log((level), __func__, __LINE__, true, \ + __VA_ARGS__) -# if MIN_LOG_LEVEL <= INFO_LOG_LEVEL -# undef ILOG -# undef ILOGN -# define ILOG(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, true, \ - __VA_ARGS__) -# define ILOGN(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, false, \ - __VA_ARGS__) -# endif +#if MIN_LOG_LEVEL <= DEBUG_LOG_LEVEL +# undef DLOG +# undef DLOGN +# define DLOG(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, true, \ + __VA_ARGS__) +# define DLOGN(...) do_log(DEBUG_LOG_LEVEL, __func__, __LINE__, false, \ + __VA_ARGS__) +#endif -# if MIN_LOG_LEVEL <= WARNING_LOG_LEVEL -# undef WLOG -# undef WLOGN -# define WLOG(...) do_log(WARNING_LOG_LEVEL, __func__, __LINE__, true, \ - __VA_ARGS__) -# define WLOGN(...) do_log(WARNING_LOG_LEVEL, __func__, __LINE__, false, \ - __VA_ARGS__) -# endif +#if MIN_LOG_LEVEL <= INFO_LOG_LEVEL +# undef ILOG +# undef ILOGN +# define ILOG(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, true, \ + __VA_ARGS__) +# define ILOGN(...) do_log(INFO_LOG_LEVEL, __func__, __LINE__, false, \ + __VA_ARGS__) +#endif -# if MIN_LOG_LEVEL <= ERROR_LOG_LEVEL -# undef ELOG -# undef ELOGN -# define ELOG(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, true, \ - __VA_ARGS__) -# define ELOGN(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, false, \ - __VA_ARGS__) -# endif +#if MIN_LOG_LEVEL <= WARNING_LOG_LEVEL +# undef WLOG +# undef WLOGN +# define WLOG(...) do_log(WARNING_LOG_LEVEL, __func__, __LINE__, true, \ + __VA_ARGS__) +# define WLOGN(...) do_log(WARNING_LOG_LEVEL, __func__, __LINE__, false, \ + __VA_ARGS__) +#endif +#if MIN_LOG_LEVEL <= ERROR_LOG_LEVEL +# undef ELOG +# undef ELOGN +# define ELOG(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, true, \ + __VA_ARGS__) +# define ELOGN(...) do_log(ERROR_LOG_LEVEL, __func__, __LINE__, false, \ + __VA_ARGS__) #endif #ifdef INCLUDE_GENERATED_DECLARATIONS diff --git a/src/nvim/main.c b/src/nvim/main.c index 46607da6ea..19a661d7db 100644 --- a/src/nvim/main.c +++ b/src/nvim/main.c @@ -153,10 +153,11 @@ void event_init(void) terminal_init(); } -void event_teardown(void) +/// @returns false if main_loop could not be closed gracefully +bool event_teardown(void) { if (!main_loop.events) { - return; + return true; } multiqueue_process_events(main_loop.events); @@ -168,7 +169,7 @@ void event_teardown(void) signal_teardown(); terminal_teardown(); - loop_close(&main_loop, true); + return loop_close(&main_loop, true); } /// Performs early initialization. diff --git a/src/nvim/msgpack_rpc/channel.c b/src/nvim/msgpack_rpc/channel.c index 413b800af5..68ac35bc4e 100644 --- a/src/nvim/msgpack_rpc/channel.c +++ b/src/nvim/msgpack_rpc/channel.c @@ -370,7 +370,7 @@ static void receive_msgpack(Stream *stream, RBuffer *rbuf, size_t c, char buf[256]; snprintf(buf, sizeof(buf), "ch %" PRIu64 " was closed by the client", channel->id); - call_set_error(channel, buf); + call_set_error(channel, buf, WARNING_LOG_LEVEL); goto end; } @@ -409,7 +409,7 @@ static void parse_msgpack(Channel *channel) "ch %" PRIu64 " returned a response with an unknown request " "id. Ensure the client is properly synchronized", channel->id); - call_set_error(channel, buf); + call_set_error(channel, buf, ERROR_LOG_LEVEL); } msgpack_unpacked_destroy(&unpacked); // Bail out from this event loop iteration @@ -459,7 +459,7 @@ static void handle_request(Channel *channel, msgpack_object *request) snprintf(buf, sizeof(buf), "ch %" PRIu64 " sent an invalid message, closed.", channel->id); - call_set_error(channel, buf); + call_set_error(channel, buf, ERROR_LOG_LEVEL); } api_clear_error(&error); return; @@ -564,7 +564,7 @@ static bool channel_write(Channel *channel, WBuffer *buffer) "Before returning from a RPC call, ch %" PRIu64 " was " "closed due to a failed write", channel->id); - call_set_error(channel, buf); + call_set_error(channel, buf, ERROR_LOG_LEVEL); } return success; @@ -795,9 +795,9 @@ static void complete_call(msgpack_object *obj, Channel *channel) } } -static void call_set_error(Channel *channel, char *msg) +static void call_set_error(Channel *channel, char *msg, int loglevel) { - ELOG("RPC: %s", msg); + LOG(loglevel, "RPC: %s", msg); for (size_t i = 0; i < kv_size(channel->call_stack); i++) { ChannelCallFrame *frame = kv_A(channel->call_stack, i); frame->returned = true; diff --git a/src/nvim/msgpack_rpc/server.c b/src/nvim/msgpack_rpc/server.c index c9edd05dc2..1e0cc27886 100644 --- a/src/nvim/msgpack_rpc/server.c +++ b/src/nvim/msgpack_rpc/server.c @@ -125,7 +125,7 @@ bool server_owns_pipe_address(const char *path) int server_start(const char *endpoint) { if (endpoint == NULL || endpoint[0] == '\0') { - ELOG("Empty or NULL endpoint"); + WLOG("Empty or NULL endpoint"); return 1; } @@ -151,7 +151,7 @@ int server_start(const char *endpoint) result = socket_watcher_start(watcher, MAX_CONNECTIONS, connection_cb); if (result < 0) { - ELOG("Failed to start server: %s", uv_strerror(result)); + WLOG("Failed to start server: %s", uv_strerror(result)); socket_watcher_close(watcher, free_server); return result; } diff --git a/src/nvim/os/shell.c b/src/nvim/os/shell.c index 1a40309655..8767287cf3 100644 --- a/src/nvim/os/shell.c +++ b/src/nvim/os/shell.c @@ -685,7 +685,7 @@ static void shell_write_cb(Stream *stream, void *data, int status) uv_err_name(status)); } if (stream->closed) { // Process may have exited before this write. - ELOG("stream was already closed"); + WLOG("stream was already closed"); return; } stream_close(stream, NULL, NULL); diff --git a/src/nvim/os_unix.c b/src/nvim/os_unix.c index fb648fbcf8..692bcc97f4 100644 --- a/src/nvim/os_unix.c +++ b/src/nvim/os_unix.c @@ -141,7 +141,9 @@ void mch_exit(int r) FUNC_ATTR_NORETURN ui_flush(); ml_close_all(true); // remove all memfiles - event_teardown(); + if (!event_teardown() && r == 0) { + r = 1; // Exit with error if main_loop did not teardown gracefully. + } stream_set_blocking(input_global_fd(), true); // normalize stream (#2598) #ifdef EXITFREE diff --git a/src/nvim/testdir/runtest.vim b/src/nvim/testdir/runtest.vim index fa3c0a6ad0..117ba52eb6 100644 --- a/src/nvim/testdir/runtest.vim +++ b/src/nvim/testdir/runtest.vim @@ -74,7 +74,7 @@ set backspace= set nohidden smarttab noautoindent noautoread complete-=i noruler noshowcmd set listchars=eol:$ " Prevent Nvim log from writing to stderr. -let $NVIM_LOG_FILE='Xnvim.log' +let $NVIM_LOG_FILE = exists($NVIM_LOG_FILE) ? $NVIM_LOG_FILE : 'Xnvim.log' func RunTheTest(test) echo 'Executing ' . a:test diff --git a/src/nvim/testdir/shared.vim b/src/nvim/testdir/shared.vim index 784e4a0a02..72cfea96c6 100644 --- a/src/nvim/testdir/shared.vim +++ b/src/nvim/testdir/shared.vim @@ -187,7 +187,7 @@ func RunVim(before, after, arguments) endfunc func RunVimPiped(before, after, arguments, pipecmd) - let $NVIM_LOG_FILE='Xnvim.log' + let $NVIM_LOG_FILE = exists($NVIM_LOG_FILE) ? $NVIM_LOG_FILE : 'Xnvim.log' let cmd = GetVimCommand() if cmd == '' return 0 diff --git a/test/README.md b/test/README.md index 2857cc0ecf..01db5960cd 100644 --- a/test/README.md +++ b/test/README.md @@ -2,6 +2,8 @@ Tests are run by `/cmake/RunTests.cmake` file, using busted. +For some failures, `.nvimlog` (or `$NVIM_LOG_FILE`) may provide insight. + ## Directory structure Directories with tests: `/test/benchmark` for benchmarks, `/test/functional` for diff --git a/test/functional/helpers.lua b/test/functional/helpers.lua index 62b0ce1200..b8512c0ad6 100644 --- a/test/functional/helpers.lua +++ b/test/functional/helpers.lua @@ -174,7 +174,7 @@ local os_name = (function() end)() local function iswin() - return os_name() == 'windows' + return package.config:sub(1,1) == '\\' end -- Executes a VimL function. diff --git a/test/functional/options/defaults_spec.lua b/test/functional/options/defaults_spec.lua index dc73679bb4..b83b7b8eee 100644 --- a/test/functional/options/defaults_spec.lua +++ b/test/functional/options/defaults_spec.lua @@ -8,6 +8,8 @@ local clear = helpers.clear local eval = helpers.eval local eq = helpers.eq local neq = helpers.neq +local mkdir = helpers.mkdir +local rmdir = helpers.rmdir local function init_session(...) local args = { helpers.nvim_prog, '-i', 'NONE', '--embed', @@ -121,6 +123,56 @@ describe('startup defaults', function() it('v:progpath is set to the absolute path', function() eq(eval("fnamemodify(v:progpath, ':p')"), eval('v:progpath')) end) + + describe('$NVIM_LOG_FILE', function() + -- TODO(jkeyes): use stdpath('data') instead. + local datasubdir = helpers.iswin() and 'nvim-data' or 'nvim' + local xdgdir = 'Xtest-startup-xdg-logpath' + local xdgdatadir = xdgdir..'/'..datasubdir + after_each(function() + os.remove('Xtest-logpath') + rmdir(xdgdir) + end) + + it('is used if expansion succeeds', function() + clear({env={ + NVIM_LOG_FILE='Xtest-logpath', + }}) + eq('Xtest-logpath', eval('$NVIM_LOG_FILE')) + end) + it('defaults to stdpath("data")/log if empty', function() + eq(true, mkdir(xdgdir) and mkdir(xdgdatadir)) + clear({env={ + XDG_DATA_HOME=xdgdir, + NVIM_LOG_FILE='', -- Empty is invalid. + }}) + -- server_start() calls ELOG, which tickles log_path_init(). + pcall(command, 'call serverstart(serverlist()[0])') + + eq(xdgdir..'/'..datasubdir..'/log', string.gsub(eval('$NVIM_LOG_FILE'), '\\', '/')) + end) + it('defaults to stdpath("data")/log if invalid', function() + eq(true, mkdir(xdgdir) and mkdir(xdgdatadir)) + clear({env={ + XDG_DATA_HOME=xdgdir, + NVIM_LOG_FILE='.', -- Any directory is invalid. + }}) + -- server_start() calls ELOG, which tickles log_path_init(). + pcall(command, 'call serverstart(serverlist()[0])') + + eq(xdgdir..'/'..datasubdir..'/log', string.gsub(eval('$NVIM_LOG_FILE'), '\\', '/')) + end) + it('defaults to .nvimlog if stdpath("data") is invalid', function() + clear({env={ + XDG_DATA_HOME='Xtest-missing-xdg-dir', + NVIM_LOG_FILE='.', -- Any directory is invalid. + }}) + -- server_start() calls ELOG, which tickles log_path_init(). + pcall(command, 'call serverstart(serverlist()[0])') + + eq('.nvimlog', eval('$NVIM_LOG_FILE')) + end) + end) end) describe('XDG-based defaults', function() |