New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[RDY] Always enable logging #6827

Merged
merged 10 commits into from Jun 7, 2017

Conversation

Projects
None yet
4 participants
@justinmk
Member

justinmk commented May 30, 2017

Goals of this PR:

  • change the default log location to ~/.local/share/nvim/log
  • set NVIM_LOG_FILE to the default path if it is undefined
  • Establish ERROR log level as critical, rare errors that must be logged. There are cases where we have no visibility in hangs/crashes because logging is disabled.
    • With this established, log file for end-users should be small or non-existent, unless there was a severe problem.
  • Always enable logging, even for "Release" builds. If logging is not noisy then this doesn't affect end-users.
  • remove DISABLE_LOG
  • Travis CI: dump the contents of the log file after each run
  • documentation

Future PR:

  • nvim_log(level, message) API function
  • update API clients (python, etc.) to use nvim_log() for critical messages
  • stdpath('log') ?
  • log Vim errors that happen during shutdown #6827 (comment)

@justinmk justinmk force-pushed the justinmk:log2 branch from b6f4a66 to 84b7d3a May 30, 2017

// Some libuv resource was not correctly deref'd. Log and bail.
log_uv_handles(&loop->uv);
break;
}

This comment has been minimized.

@justinmk

justinmk May 30, 2017

Member

If loop_close takes longer than 2 seconds it is most likely an infinite loop. So, log the state and exit the loop.

@@ -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);

This comment has been minimized.

@justinmk

justinmk May 30, 2017

Member

This is usually not a failure mode, but a normal situation. So don't log it at ERROR level.

@justinmk justinmk force-pushed the justinmk:log2 branch from 84b7d3a to 61339f3 May 30, 2017

@@ -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 in garray(%d), should be %d", item_size);

This comment has been minimized.

@oni-link

oni-link May 30, 2017

Contributor

Are we missing a size argument here?

This comment has been minimized.

@justinmk

justinmk May 30, 2017

Member

Looks like it :)

@justinmk justinmk force-pushed the justinmk:log2 branch 3 times, most recently from a5bc0ee to 205c680 May 31, 2017

@blueyed

This comment has been minimized.

Contributor

blueyed commented Jun 1, 2017

Nice!
btw: would it be possible to also log Vim errors, especially when they happen on shutdown/quitting?
(I've just seen some when quitting Neovim slightly pop up in red, but then it is gone already)

.travis.yml Outdated
@@ -21,8 +21,6 @@ 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"

This comment has been minimized.

@blueyed

blueyed Jun 1, 2017

Contributor

Seems to be cleaner to keep it here, no?
Is $BUILD_DIR already setup here (defined above)? (but it seems to work for $LOG_DIR?!)

This comment has been minimized.

@justinmk

justinmk Jun 1, 2017

Member

@blueyed That's part of the temporary commits, I am puzzled about why travis is failing.

@@ -141,7 +141,8 @@ void mch_exit(int r) FUNC_ATTR_NORETURN
ui_flush();
ml_close_all(true); // remove all memfiles

event_teardown();
// Exit with error if main_loop did not teardown gracefully.
r = event_teardown() ? r : (r || 1);

This comment has been minimized.

@oni-link

oni-link Jun 1, 2017

Contributor

Why use (r||1) here, it is always 1?

This comment has been minimized.

@justinmk

justinmk Jun 1, 2017

Member

@oni-link You're right, that needs to be a ternary. The intention is to preserve the value of r > 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.
memset(log_file_path, 0, size);

This comment has been minimized.

@oni-link

oni-link Jun 2, 2017

Contributor

This could be removed. The following xstrlcpy() will overwrite this buffer and terminate it with NUL.

xfree(defaultpath);
// Fall back to .nvimlog
if (len >= size || !log_try_create(log_file_path)) {
len = xstrlcpy(log_file_path, ".nvimlog", sizeof(".nvimlog"));

This comment has been minimized.

@oni-link

oni-link Jun 2, 2017

Contributor

sizeof(".nvimlog") is not the size that is expected here, it should be the size of the destination buffer.

}
// Fall back to stderr
if (len >= size || !log_try_create(log_file_path)) {
memset(log_file_path, 0, size);

This comment has been minimized.

@oni-link

oni-link Jun 2, 2017

Contributor

log_file_path[0]=NUL; should be enough to mark the buffer as empty.

@justinmk justinmk force-pushed the justinmk:log2 branch 5 times, most recently from d6aa388 to 6617c97 Jun 5, 2017

@justinmk justinmk changed the title from Always enable logging to [RDY] Always enable logging Jun 6, 2017

@justinmk justinmk force-pushed the justinmk:log2 branch 3 times, most recently from 020bbf3 to ab6d0e1 Jun 6, 2017

justinmk added some commits May 28, 2017

loop_close: Avoid infinite loop, and log it.
Avoids a hang, and also helps diagnose issues like:

#6594 (comment)
log: Always enable; remove DISABLE_LOG
- Establish ERROR log level as "critical". Such errors are rare and will
  be valuable when users encounter unusual circumstances.
- Set -DMIN_LOG_LEVEL=3 for release-type builds
test: Set $NVIM_LOG_FILE to test-local path
- Do not delete it: may need to inspect it after tests finished.
- Avoids writing to stderr in cases where the test-local $XDG_DATA_HOME
  was not created yet.

justinmk added some commits May 31, 2017

log: Fall back to CWD-relative .nvimlog
If if the resolved $NVIM_LOG_FILE *and* stdpath("data")/log cannot be
created (e.g. because the XDG data directory does not exist), fall back
to .nvimlog in the current direcrtory.

@justinmk justinmk force-pushed the justinmk:log2 branch from ab6d0e1 to bc025ab Jun 6, 2017

@justinmk justinmk merged commit 16cce1a into neovim:master Jun 7, 2017

2 of 3 checks passed

QuickBuild Build pr-6827 finished with status FAILED
Details
continuous-integration/appveyor/pr AppVeyor build succeeded
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details

@justinmk justinmk deleted the justinmk:log2 branch Jun 7, 2017

justinmk added a commit to justinmk/neovim that referenced this pull request Jun 7, 2017

[WIP] Make logging great again
- [ ] `nvim_log(level, message)` API function
- [ ] update API clients (python, etc.) to use `nvim_log()` for critical messages
- [ ] `stdpath('log')` ?
- [ ] log Vim errors that happen during shutdown neovim#6827 (comment)
@jdebp

This comment has been minimized.

Contributor

jdebp commented Jun 8, 2017

Development-tips on the wiki needs to be brought up-to-date.

justinmk added a commit to justinmk/neovim that referenced this pull request Jun 26, 2017

cmake: Remove custom "Dev" build-type.
The main purpose of this build-type was to avoid unwanted ~/.nvimlog
files (which could get really big, and also affects performance) for
non-devs. But that is no longer necessary since the log system now
avoids non-critical logging by default (neovim#6827).

This essentially reverts 87e5a41

justinmk added a commit that referenced this pull request Jun 29, 2017

cmake: Remove custom "Dev" build-type. (#6932)
The main purpose of this build-type was to avoid unwanted ~/.nvimlog
files (which could get really big, and also affects performance) for
non-devs. But that is no longer necessary since the log system now
avoids non-critical logging by default (#6827).

This essentially reverts 87e5a41

justinmk added a commit to justinmk/neovim that referenced this pull request Jul 23, 2017

[WIP] log: nvim_log API
- [ ] `nvim_log(level, message)` API function
- [ ] update API clients (python, etc.) to use `nvim_log()` for critical messages
- [ ] `stdpath('log')` ?
- [ ] log Vim errors that happen during shutdown neovim#6827 (comment)

@justinmk justinmk referenced this pull request Jul 23, 2017

Open

[WIP] log: nvim_log API #7062

0 of 4 tasks complete

justinmk added a commit to justinmk/neovim that referenced this pull request Nov 8, 2017

NVIM v0.2.1
FEATURES:
0e873a3 Lua(Jit) built-in neovim#4411
5b32bce Windows: `:terminal` neovim#7007
7b0ceb3 UI/API: externalize cmdline neovim#7173
b67f58b UI/API: externalize wildmenu neovim#7454
b23aa1c UI: 'winhighlight' neovim#6597
17531ed UI: command-line coloring (`:help input()-highlight`) neovim#6364
244a1f9 API: execute lua directly from the remote api neovim#6704
45626de API: `get_keymap()` neovim#6236
db99982 API: `nvim_get_hl_by_name()`, `nvim_get_hl_by_id()` neovim#7082
dc68538 menu_get() function neovim#6322
9db42d4 :cquit : take an error code argument neovim#7336
9cc185d job-control: serverstart(): support ipv6 neovim#6680
1b7a9bf job-control: sockopen() neovim#6594
6efe84a clipboard: fallback to tmux clipboard neovim#6894
6016ac2 clipboard: customize clipboard with `g:clipboard` neovim#6030
3a86dd5 ruby: override ruby host via `g:ruby_host_prog` neovim#6841
16cce1a debug: $NVIM_LOG_FILE neovim#6827
0cba3da `:checkhealth` built-in, validates $VIMRUNTIME neovim#7399

FIXES:
105d680 TUI: more terminals, improve scroll/resize neovim#6816
cb912a3 :terminal : handle F1-F12, other keys neovim#7241
619838f inccommand: improve performance neovim#6949
04b3c32 inccommand: Fix matches for zero-width neovim#7487
60b1e8a inccommand: multiline, other fixes neovim#7315
f1f7f3b inccommand: Ignore leading modifiers in the command neovim#6967
1551f71 inccommand: fix 'gdefault' lockup neovim#7262
6338199 API: bufhl: support creating new groups neovim#7414
541dde3 API: allow K_EVENT during operator-pending
8c732f7 terminal: adjust for 'number' neovim#7440
5bec946 UI: preserve wildmenu during jobs/events neovim#7110
c349083 UI: disable 'lazyredraw' during ui_refresh. neovim#6259
51808a2 send FocusGained/FocusLost event instead of pseudokey neovim#7221
133f8bc shada: preserve unnamed register on restart neovim#4700
1b70a1d shada: avoid assertion on corrupt shada file neovim#6958
9f534f3 mksession: Restore tab-local working directory neovim#6859
de1084f fix buf_write() crash neovim#7140
7f76986 syntax: register 'Normal' highlight group neovim#6973
6e7a8c3 RPC: close channel if stream was closed neovim#7081
85f3084 clipboard: disallow recursion; show hint only once neovim#7203
8d1ccb6 clipboard: performance, avoid weird edge-cases neovim#7193
01487d4 'titleold' neovim#7358
01e53a5 Windows: better path-handling, separator (slash) hygiene neovim#7349
0f2873c Windows: multibyte startup arguments neovim#7060

CHANGES:
9ff0cc7 :terminal : start in normal-mode neovim#6808
032b088 lower priority of 'cursorcolumn', 'colorcolumn' neovim#7364
2a3bcd1 RPC: Don't delay notifications when request is pending neovim#6544
023f67c :terminal : Do not change 'number', 'relativenumber' neovim#6796
1ef2d76 socket.c: Disable Nagle's algorithm on TCP sockets neovim#6915
6720fe2 help: `K` tries Vim help instead of manpage neovim#3104
7068370 help, man.vim: change "outline" map to `gO` neovim#7405

@justinmk justinmk referenced this pull request Nov 8, 2017

Merged

NVIM v0.2.1 #7505

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment