aboutsummaryrefslogtreecommitdiff
path: root/src/nvim/log.c
Commit message (Collapse)AuthorAge
* refactor: fix headers with IWYUdundargoc2023-11-28
|
* build(IWYU): fix includes for func_attr.hdundargoc2023-11-27
|
* build(IWYU): replace most private mappings with pragmas (#26247)zeertzjq2023-11-27
|
* refactor: enable formatting for ternariesdundargoc2023-11-20
| | | | | | This requires removing the "Inner expression should be aligned" rule from clint as it prevents essentially any formatting regarding ternary operators.
* build: remove PVSdundargoc2023-11-12
| | | | | | | We already have an extensive suite of static analysis tools we use, which causes a fair bit of redundancy as we get duplicate warnings. PVS is also prone to give false warnings which creates a lot of work to identify and disable.
* refactor(change): do API changes to buffer without curbuf switchbfredl2023-08-26
| | | | | | | | | | | | | | | | | | | | | | | Most of the messy things when changing a non-current buffer is not about the buffer, it is about windows. In particular, it is about `curwin`. When editing a non-current buffer which is displayed in some other window in the current tabpage, one such window will be "borrowed" as the curwin. But this means if two or more non-current windows displayed the buffers, one of them will be treated differenty. this is not desirable. In particular, with nvim_buf_set_text, cursor _column_ position was only corrected for one single window. Two new tests are added: the test with just one non-current window passes, but the one with two didn't. Two corresponding such tests were also added for nvim_buf_set_lines. This already worked correctly on master, but make sure this is well-tested for future refactors. Also, nvim_create_buf no longer invokes autocmds just because you happened to use `scratch=true`. No option value was changed, therefore OptionSet must not be fired.
* build: update uncrustify to 0.76Lewis Russell2023-04-19
|
* vim-patch:9.0.0411: only created files can be cleaned up with one callzeertzjq2023-04-16
| | | | | | | | | | | | | | | | | | | | | | Problem: Only created files can be cleaned up with one call. Solution: Add flags to mkdir() to delete with a deferred function. Expand the writefile() name to a full path to handle changing directory. https://github.com/vim/vim/commit/6f14da15ac900589f2f413d77898b9bff3b31ece vim-patch:8.2.3742: dec mouse test fails without gnome terminfo entry Problem: Dec mouse test fails without gnome terminfo entry. Solution: Check if there is a gnome entry. Also fix 'acd' test on MS-Windows. (Dominique Pellé, closes vim/vim#9282) https://github.com/vim/vim/commit/f589fd3e1047cdf90566b68aaf9a13389e54d26a Cherry-pick test_autochdir.vim changes from patch 9.0.0313. Cherry-pick test_autocmd.vim changes from patch 9.0.0323. Co-authored-by: Bram Moolenaar <Bram@vim.org>
* refactor(log): reduce compile time LOG_LEVEL granularitybfredl2023-03-04
|
* build: allow IWYU to fix includes for all .c filesdundargoc2022-11-15
| | | | | | | | | | Allow Include What You Use to remove unnecessary includes and only include what is necessary. This helps with reducing compilation times and makes it easier to visualise which dependencies are actually required. Work on https://github.com/neovim/neovim/issues/549, but doesn't close it since this only works fully for .c files and not headers.
* refactor: replace char_u with char 4 (#19987)dundargoc2022-08-30
| | | | | | | * refactor: replace char_u with char Work on https://github.com/neovim/neovim/issues/459
* refactor: replace char_u with charDundar Göc2022-08-29
| | | | Work on https://github.com/neovim/neovim/issues/459
* refactor: fix clang and PVS warnings (#19532)zeertzjq2022-07-28
|
* fix(logging): try harder to resolve Nvim "name" #19016Justin M. Keyes2022-06-18
| | | | | | | | | | | Problem: If startup finishes (starting=false) before the logger ever happens to see a v:servername, we're stuck with the "?.<PID>" fallback name forever. Solution: Drop the `starting` condition. Discard the "?.<PID>" fallback after using it for the current log message. So logging will always check v:servername next time.
* feat(server): instance "name", store pipes in stdpath(state)Justin M. Keyes2022-06-15
| | | | | | | | | | | | | | | | | | Problem: - Unix sockets are created in random /tmp dirs. - /tmp is messy, unclear when OSes actually clear it. - The generated paths are very ugly. This adds friction to reasoning about which paths belong to which Nvim instances. - No way to provide a human-friendly way to identify Nvim instances in logs or server addresses. Solution: - Store unix sockets in stdpath('state') - Allow --listen "name" and serverstart("name") to given a name (which is appended to a generated path). TODO: - is stdpath(state) the right place?
* feat(logging): include test-id in log messagesJustin M. Keyes2022-06-15
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | Problem: 1. Log messages (especially in CI) are hard to correlate with tests. 2. Since b353a5c05f02 #11886, dumplog() prints the logs next to test failures. This is noisy and gets in the way of the test results. Solution: 1. Associate an incrementing id with each test and include it in log messages. - FUTURE: add v:name so Nvim instances can be formally "named"? 2. Mention "child" in log messages if the current Nvim is a child (based on the presence of $NVIM). BEFORE: DBG … 12345 UI: event DBG … 12345 log_server_msg:722: RPC ->ch 1: … DBG … 12345 UI: flush DBG … 12345 inbuf_poll:444: blocking... events_enabled=1 events_pending=0 DBG … 23454 UI: stop INF … 23454 os_exit:594: Nvim exit: 0 AFTER: DBG … T57 UI: event DBG … T57 log_server_msg:722: RPC ->ch 1: … DBG … T57 UI: flush DBG … T57 inbuf_poll:444: blocking... events_enabled=1 events_pending=0 DBG … T57/child UI: stop INF … T57/child os_exit:594: Nvim exit: 0
* refactor(log): use msg_schedule_semsg #18950Justin M. Keyes2022-06-15
|
* refactor(log): simplify log_path_init #18898Justin M. Keyes2022-06-08
| | | | | | | | | Problem: Since 22b52dd462e5 #11501, log_path_init is called in log_init, so it is now called at a deterministic time. So the "just in time" complexity of log_path_init is no longer needed. Solution: Remove logic intended to try to "heal" partial initialization.
* fix(log): back even againbfredl2022-06-03
|
* fix(logging): make logmsg() thread-safe againbfredl2022-06-03
| | | | | | | | | problem: data race when `recursive` is read outside of mutex by thread A while thread B has taken the mutex and modifies it. solution: use a recursive lock. ref #18764
* fix(logging): skip recursion, fix crash #18764Justin M. Keyes2022-05-30
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | Problem: 1. The main log routine does not protect itself against recursion. log_lock() doesn't guard against recursion, it would deadlock... 2. 22b52dd462e5 (#11501) regressed 6f27f5ef91b3 (#10172), because set_init_1..process_spawn tries to log (see backtrace below), but the mutex isn't initialized yet. Even if the mutex were valid, we don't want early logging to fallback to stderr because that can break embedders when stdio is used for RPC. frame 1: 0x00000001001d54f4 nvim`open_log_file at log.c:205:7 frame 2: 0x00000001001d5390 nvim`logmsg(log_level=1, context="UI: ", func_name=0x0000000000000000, line_num=-1, eol=true, fmt="win_viewport") at log.c:150:20 frame : 0x000000010039aea2 nvim`ui_call_win_viewport(grid=2, win=1000, topline=0, botline=1, curline=0, curcol=0, line_count=1) at ui_events_call.generated.h:321:3 frame 4: 0x00000001003dfefc nvim`ui_ext_win_viewport(wp=0x0000000101816400) at window.c:939:5 frame 5: 0x00000001003ec5b4 nvim`win_ui_flush at window.c:7303:7 frame 6: 0x00000001003a04c0 nvim`ui_flush at ui.c:508:3 frame 7: 0x00000001002966ba nvim`do_os_system(argv=0x0000600000c0c000, input=0x0000000000000000, len=0, output=0x0000000000000000, nread=0x00007ff7bfefe830, silent=false, forward_output=false) at shell.c:894:3 frame 8: 0x0000000100295f68 nvim`os_call_shell(cmd="unset nonomatch; vimglob() { while [ $# -ge 1 ]; do echo \"$1\"; shift; done }; vimglob >/var/folders/gk/3tttv_md06987tlwpyp62jrw0000gn/T/nvimwwvwfD/0 ~foo", opts=kShellOptExpand | kShellOptSilent | kShellOptHideMess, extra_args=0x0000000000000000) at shell.c:663:18 frame 9: 0x0000000100295845 nvim`call_shell(cmd="unset nonomatch; vimglob() { while [ $# -ge 1 ]; do echo \"$1\"; shift; done }; vimglob >/var/folders/gk/3tttv_md06987tlwpyp62jrw0000gn/T/nvimwwvwfD/0 ~foo", opts=kShellOptExpand | kShellOptSilent | kShellOptHideMess, extra_shell_arg=0x0000000000000000) at shell.c:712:14 frame 10: 0x0000000100294c6f nvim`os_expand_wildcards(num_pat=1, pat=0x00007ff7bfefeb20, num_file=0x00007ff7bfefee58, file=0x00007ff7bfefee60, flags=43) at shell.c:328:7 ... frame 23: 0x000000010028ccef nvim`expand_env_esc(srcp=",~foo", dst="~foo", dstlen=4094, esc=false, one=false, prefix=0x0000000000000000) at env.c:673:17 frame 24: 0x000000010026fdd5 nvim`option_expand(opt_idx=29, val=",~foo") at option.c:1950:3 frame 25: 0x000000010026f129 nvim`set_init_1(clean_arg=false) at option.c:558:19 frame 26: 0x00000001001ea25e nvim`early_init(paramp=0x00007ff7bfeff5f0) at main.c:198:3 frame 27: 0x00000001001ea6bf nvim`main(argc=1, argv=0x00007ff7bfeff848) at main.c:255:3 Solution: 1. Check for recursion, show "internal error" message. - FUTURE: when "remote TUI" is merged, can we remove log_lock()? 2. Skip logging if log_init wasn't called yet.
* feat(defaults): session data in $XDG_STATE_HOME #15583Ivan2022-05-12
| | | | | | | | | | | | See: https://gitlab.freedesktop.org/xdg/xdg-specs/-/commit/4f2884e16db35f2962d9b64312917c81be5cb54b - Move session persistent data to $XDG_STATE_HOME Change 'directory', 'backupdir', 'undodir', 'viewdir' and 'shadafile' default location to $XDG_STATE_HOME/nvim. - Move logs to $XDG_STATE_HOME, too. - Add stdpath('log') support. Fixes: #14805
* chore: add additional compiler flags (#17815)Lewis Russell2022-03-24
| | | | | | | | | Added: - -Wdouble-promotion - -Wmissing-noreturn - -Wmissing-format-attribute - -Wsuggest-attribute={pure,const,malloc,cold} Resolves: #343
* refactor: reformat with uncrustify #15736dundargoc2021-09-20
| | | | * fix function parameter comments * remove space after star in function names
* log.c: warn instead of error on failed stdpath('cache') creationMichael Lingelbach2021-01-16
|
* logs: make kXDGCacheHome if it doesn't exist (#13758)Michael Lingelbach2021-01-16
|
* logging: move to XDG_CACHE_HOME (#13739)Michael Lingelbach2021-01-13
| | | | | while there is some controversy, stdpath('cache') looks like a better fit for logs than stdpath('data'): you can remove logs without preventing nvim to work which fits the XDG_CACHE_HOME definition of `user specific non-essential data files`.
* log: use uv_gettimeofday() for WindowsJan Edmund Lazo2020-12-06
| | | | POSIX gettimeofday() is not portable.
* log_init: call log_path_init (#11501)Daniel Hahler2019-12-02
| | | | | | | | This has to be done after `init_homedir` for XDG default and `set_init_1` for lookup from env, which could be done earlier likely (to help with https://github.com/neovim/neovim/issues/10937), but this keeps it in sync with Vim. Fixes https://github.com/neovim/neovim/issues/11499.
* Remove excess <stdint.h>Jan Edmund Lazo2019-09-11
|
* doc [ci skip]Justin M. Keyes2019-04-08
| | | | - README.md: Removed waffle.io because that service is shutting down.
* build: include auto/config.h explicitlyJustin M. Keyes2019-01-20
| | | | | Otherwise the symbols defined in config/config.h.in may not be defined, depending on include-order.
* Merge #9036 'func_attr_printf'Justin M. Keyes2018-10-07
|\
| * fixed lint errorsMichaHoffmann2018-09-24
| |
| * add func_attr_printf in :MichaHoffmann2018-09-24
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | log.c message.c strings.c fixed some printf warnings in: src/nvim/undo.c src/nvim/eval.c src/nvim/eval/encode.c src/nvim/eval/typval.c src/nvim/ex_getln.c src/nvim/fileio.c src/nvim/lua/executor.c src/nvim/main.c src/nvim/regexp_nfa.c src/nvim/shada.c src/nvim/spellfile.c src/nvim/tui/terminfo.c src/nvim/garray.h
* | log: Assert that we haven't started freeing memory before loggingJames McCoy2018-09-24
|/ | | | | This is to catch situations like the previous commit, which somehow avoided detection by any of the CI builds.
* log: rename do_log to logmsgJustin M. Keyes2018-09-19
|
* log.c: Fix possible truncation in buffer (#8791)hyatskov2018-07-29
|
* log.c: format: paddingJustin M. Keyes2018-07-25
| | | | | - milliseconds: leading zeroes - PID: whitespace padding
* log.c: ISO 8601 date/timeJustin M. Keyes2018-07-24
| | | | | After: INFO 2018-07-17T22:05:46.175 656 main:560: starting main loop
* log.c: include millisecondsJustin M. Keyes2018-07-24
| | | | | | | | | | | | | closes #8727 Before: INFO 180711.233956 11124 main:560: starting main loop After: INFO 180711.233956.807 11124 main:560: starting main loop Note: - Can't use uv_hrtime() nor uv_now(), they are not "since the epoch". Also, log.c can't assume a loop exists.
* log.c: message formatJustin M. Keyes2018-07-24
| | | | | | | | | | | | - Log-level name (INFO/ERROR/…) should be in the first column, so that filtering by log-level is maximally trivial. - Use 2-digit year. 4-digit year is useless, logs don't survive for decades without context. Before: 2018/07/05 17:49:41 INFO 27596 on_process_exit:393: foo After: INFO 180705.174941 27596 on_process_exit:393: foo
* rename: os_get_localtime => os_localtimeJustin M. Keyes2018-07-24
|
* lintJustin M. Keyes2017-09-05
|
* log: introduce `context`Justin M. Keyes2017-09-05
|
* rpc: close channel if stream was closedJustin M. Keyes2017-08-21
| | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | | f_jobstop()/f_rpcstop() .. process_stop() .. process_close_in(proc) closes the write-stream of a RPC channel. But there might be a pending RPC notification on the queue, which may get processed just before the channel is closed. To handle that case, check the Stream.closed in channel.c:receive_msgpack(). Before this change, the above scenario could trigger this assert(!stream->closed) in wstream_write(): 0x00007f96e1cd3428 in __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:54 0x00007f96e1cd502a in __GI_abort () at abort.c:89 0x00007f96e1ccbbd7 in __assert_fail_base (fmt=<optimized out>, assertion=assertion@entry=0x768f9b "!stream->closed", file=file@entry=0x768f70 "../src/nvim/event/wstream.c", line=line@entry=77, function=function@entry=0x768fb0 <__PRETTY_FUNCTION__.13735> "wstream_write") at assert.c:92 0x00007f96e1ccbc82 in __GI___assert_fail (assertion=0x768f9b "!stream->closed", file=0x768f70 "../src/nvim/event/wstream.c", line=77, function=0x768fb0 <__PRETTY_FUNCTION__.13735> "wstream_write") at assert.c:101 0x00000000004d2c1f in wstream_write (stream=0x7f96e0a35078, buffer=0x7f96e09f9b40) at ../src/nvim/event/wstream.c:77 0x00000000005857b2 in channel_write (channel=0x7f96e0ae5800, buffer=0x7f96e09f9b40) at ../src/nvim/msgpack_rpc/channel.c:551 0x000000000058567d in on_request_event (argv=0x7ffed792efa0) at ../src/nvim/msgpack_rpc/channel.c:523 0x00000000005854c8 in handle_request (channel=0x7f96e0ae5800, request=0x7ffed792f1b8) at ../src/nvim/msgpack_rpc/channel.c:503 0x00000000005850cb in parse_msgpack (channel=0x7f96e0ae5800) at ../src/nvim/msgpack_rpc/channel.c:423 0x0000000000584f90 in receive_msgpack (stream=0x7f96e0a35218, rbuf=0x7f96e0d1d4c0, c=22, data=0x7f96e0ae5800, eof=false) at ../src/nvim/msgpack_rpc/channel.c:389 0x00000000004d0b20 in read_event (argv=0x7ffed792f4a8) at ../src/nvim/event/rstream.c:190 0x00000000004ce462 in multiqueue_process_events (this=0x7f96e18172d0) at ../src/nvim/event/multiqueue.c:150 0x000000000059b630 in nv_event (cap=0x7ffed792f620) at ../src/nvim/normal.c:7908 0x000000000058be69 in normal_execute (state=0x7ffed792f580, key=-25341) at ../src/nvim/normal.c:1137 0x0000000000652463 in state_enter (s=0x7ffed792f580) at ../src/nvim/state.c:61 0x000000000058a1fe in normal_enter (cmdwin=false, noexmode=false) at ../src/nvim/normal.c:467 0x00000000005500c2 in main (argc=2, argv=0x7ffed792f8d8) at ../src/nvim/main.c:554 Alternative approach suggested by bfredl is to use close_cb of the process. My unsuccessful attempt is below. (It seems close_cb is queued too late, which is the similar problem addressed by this commit): commit 75fc12c6ab15711bdb7b18c6d42ec9d157f5145e Author: Justin M. Keyes <justinkz@gmail.com> Date: Fri Aug 18 01:30:41 2017 +0200 rpc: use Stream's close_cb instead of explicit check in receive_msgpack() diff --git a/src/nvim/event/process.c b/src/nvim/event/process.c index 8371d3cd482e..e52da23cdc40 100644 --- a/src/nvim/event/process.c +++ b/src/nvim/event/process.c @@ -416,6 +416,10 @@ static void on_process_exit(Process *proc) static void on_process_stream_close(Stream *stream, void *data) { Process *proc = data; + ILOG("on_process_stream_close"); + if (proc->stream_close_cb != NULL) { + proc->stream_close_cb(stream, proc->stream_close_data); + } decref(proc); } diff --git a/src/nvim/event/process.h b/src/nvim/event/process.h index 5c00e8e7ecd5..34a8d54f6f8c 100644 --- a/src/nvim/event/process.h +++ b/src/nvim/event/process.h @@ -26,6 +26,11 @@ struct process { Stream *in, *out, *err; process_exit_cb cb; internal_process_cb internal_exit_cb, internal_close_cb; + + // Called when any of the process streams (in/out/err) closes. + stream_close_cb stream_close_cb; + void *stream_close_data; + bool closed, detach; MultiQueue *events; }; @@ -50,6 +55,8 @@ static inline Process process_init(Loop *loop, ProcessType type, void *data) .closed = false, .internal_close_cb = NULL, .internal_exit_cb = NULL, + .stream_close_cb = NULL, + .stream_close_data = NULL, .detach = false }; } diff --git a/src/nvim/event/stream.c b/src/nvim/event/stream.c index 7c865bfe1e8c..c8720d1e45d9 100644 --- a/src/nvim/event/stream.c +++ b/src/nvim/event/stream.c @@ -95,7 +95,11 @@ void stream_close(Stream *stream, stream_close_cb on_stream_close, void *data) void stream_close_handle(Stream *stream) FUNC_ATTR_NONNULL_ALL { + ILOG("stream=%d", stream); + // LOG_CALLSTACK(); if (stream->uvstream) { + // problem: this schedules on the queue, but channel.c:receive_msgpack may + // be processed before close_cb is called by libuv. uv_close((uv_handle_t *)stream->uvstream, close_cb); } else { uv_close((uv_handle_t *)&stream->uv.idle, close_cb); @@ -105,6 +109,7 @@ void stream_close_handle(Stream *stream) static void close_cb(uv_handle_t *handle) { Stream *stream = handle->data; + ILOG(">>>>>>>>>>>>>>>>>>>>>>> stream=%p stream->internal_close_cb=%p", stream, stream->internal_close_cb); if (stream->buffer) { rbuffer_free(stream->buffer); } diff --git a/src/nvim/msgpack_rpc/channel.c b/src/nvim/msgpack_rpc/channel.c index 782eabe04e4a..dc2b794e366a 100644 --- a/src/nvim/msgpack_rpc/channel.c +++ b/src/nvim/msgpack_rpc/channel.c @@ -128,6 +128,8 @@ uint64_t channel_from_process(Process *proc, uint64_t id, char *source) source); incref(channel); // process channels are only closed by the exit_cb channel->data.proc = proc; + channel->data.proc->stream_close_cb = close_cb2; + channel->data.proc->stream_close_data = channel; wstream_init(proc->in, 0); rstream_init(proc->out, 0); @@ -387,17 +389,6 @@ static void receive_msgpack(Stream *stream, RBuffer *rbuf, size_t c, goto end; } - if ((chan_wstream(channel) != NULL && chan_wstream(channel)->closed) - || (chan_rstream(channel) != NULL && chan_rstream(channel)->closed)) { - char buf[256]; - snprintf(buf, sizeof(buf), - "ch %" PRIu64 ": stream closed unexpectedly. " - "closing channel", - channel->id); - call_set_error(channel, buf, WARN_LOG_LEVEL); - goto end; - } - size_t count = rbuffer_size(rbuf); DLOG("ch %" PRIu64 ": parsing %u bytes from msgpack Stream: %p", channel->id, count, stream); @@ -571,23 +562,6 @@ static Stream *chan_wstream(Channel *chan) abort(); } -/// Returns the Stream that a Channel reads from. -static Stream *chan_rstream(Channel *chan) -{ - switch (chan->type) { - case kChannelTypeSocket: - return &chan->data.stream; - case kChannelTypeProc: - return chan->data.proc->out; - case kChannelTypeStdio: - return &chan->data.std.in; - case kChannelTypeInternal: - return NULL; - } - abort(); -} - - static bool channel_write(Channel *channel, WBuffer *buffer) { bool success = false; @@ -799,6 +773,12 @@ static void close_cb(Stream *stream, void *data) decref(data); } +static void close_cb2(Stream *stream, void *data) +{ + ILOG("close_cb2"); + close_channel(data); +} + /// @param source description of source function, rplugin name, TCP addr, etc static Channel *register_channel(ChannelType type, uint64_t id, MultiQueue *events, char *source)
* log: Add log_callstack_to_file()James McCoy2017-08-09
| | | | | This makes it trivial to log the callstack to, e.g., stderr, which can simplify debug cycles.
* build: linux does not always have execinfo.h (#7101)Justin M. Keyes2017-07-30
| | | Closes #7099
* log: log_callstack()Justin M. Keyes2017-07-23
|
* log: Fall back to CWD-relative .nvimlogJustin M. Keyes2017-06-07
| | | | | | 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.