aboutsummaryrefslogtreecommitdiff
path: root/src/nvim/log.c
Commit message (Collapse)AuthorAge
* 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.
* log: set $NVIM_LOG_FILE; fallback to $XDG_DATA_HOME/nvim/logJustin M. Keyes2017-06-07
|
* log: Always enable; remove DISABLE_LOGJustin M. Keyes2017-06-07
| | | | | | - 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
* log: log_uv_handlesJustin M. Keyes2017-06-07
|
* *: Add comment to all C filesZyX2017-04-19
|
* log.c: align/adjust layoutJustin M. Keyes2016-09-28
| | | | | | | | New: 2016/09/27 18:00:49 INFO 28117/tui_flush:597: ... Old: 2016/09/27 18:00:49 [info @ tui_flush:597] 28117 - ...
* log: Rename to $NVIM_LOG_FILEJustin M. Keyes2016-06-05
|
* log: Move log to $NVIM_LOG_FILE_PATH, falling back to the old locationZyX2016-05-31
| | | | Closes #3561
* config: Remove HAVE_UNISTD_H.Seth Jackson2016-01-18
| | | | | | | | | Unix systems must have this header but Windows does not have it at all. Since src/nvim/os/unix_defs.h includes <unistd.h> without the guard in order to avoid including this in the numerous places we would need <unistd.h> on Unix we just include src/nvim/os/os.h which will pull in <unistd.h> for us.
* Update USR_LOG_FILE definition.Rui Abreu Ferreira2015-12-07
|
* log: Make logging thread-safeThiago de Arruda2015-09-06
|
* remove references to <sys/time.h>Justin M. Keyes2015-08-24
| | | | | Since gettimeofday() was replaced by os_time in fb5a786bdb5b7b52b9c36b3eb8b6d2cc002aa8f3 we do not need sys/time.h.
* Add header guards for sys/time.h and unistd.h in log.cRui Abreu Ferreira2015-05-21
|
* refactor: split some more functions from misc1.cbobtwinkles2015-03-24
| | | | | | | | | | | This commit pulls the some environment-variable handling functions out of misc1.c and in to os/env.c. Previously submited as #1231, this is the start of a patch series that does that work based on a more up-to-date master branch. Major tasks accomplished: - move functions and fix includes - fix clint/clang analysis warnings - correct documentation comments
* msgpack-rpc: Improve logging of msgpack-rpc messagesThiago de Arruda2014-10-23
| | | | | | | | | | - Expose more logging control from the log.c module(get log stream and omit newlines) - Remove logging from the generated functions in msgpack-gen.lua - Refactor channel.c/helpers.c to log every msgpack-rpc payload using msgpack_object_print(a helper function from msgpack.h) - Remove the api_stringify function, it was only useful for logging msgpack-rpc which is now handled by msgpack_object_print.
* Add automatic generation of headersZyX2014-06-02
| | | | | | | | | | | | | | | | | - The 'stripdecls.py' script replaces declarations in all headers by includes to generated headers. `ag '#\s*if(?!ndef NEOVIM_).*((?!#\s*endif).*\n)*#ifdef INCLUDE_GENERATED'` was used for this. - Add and integrate gendeclarations.lua into the build system to generate the required includes. - Add -Wno-unused-function - Made a bunch of old-style definitions ANSI This adds a requirement: all type and structure definitions must be present before INCLUDE_GENERATED_DECLARATIONS-protected include. Warning: mch_expandpath (path.h.generated.h) was moved manually. So far it is the only exception.
* Introduce nvim namespace: Fix project-local includes.Eliseo Martínez2014-05-15
| | | | Prepend 'nvim/' in all project-local (non-system) includes.
* Introduce nvim namespace: Move files.Eliseo Martínez2014-05-15
Move files from src/ to src/nvim/. - src/nvim/ becomes the new root dir for nvim executable sources. - src/libnvim/ is planned to become root dir of the neovim library.