Commit Graph

24 Commits

Author SHA1 Message Date
Justin M. Keyes
8716994cf0 lint 2017-09-05 15:01:07 +02:00
Justin M. Keyes
63c6470505 log: introduce context 2017-09-05 15:01:07 +02:00
Justin M. Keyes
af993da435 rpc: close channel if stream was closed
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)
2017-08-21 01:04:28 +02:00
James McCoy
17eb20b22e log: Add log_callstack_to_file()
This makes it trivial to log the callstack to, e.g., stderr, which can
simplify debug cycles.
2017-08-09 13:30:34 -04:00
Justin M. Keyes
a7538371fe build: linux does not always have execinfo.h (#7101)
Closes #7099
2017-07-30 23:02:41 +02:00
Justin M. Keyes
eb2473e9ea log: log_callstack() 2017-07-23 17:16:19 +02:00
Justin M. Keyes
d07661b9a3 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.
2017-06-07 00:27:26 +02:00
Justin M. Keyes
bb96b8219d log: set $NVIM_LOG_FILE; fallback to $XDG_DATA_HOME/nvim/log 2017-06-07 00:26:56 +02:00
Justin M. Keyes
fe1af9c2bc 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
2017-06-07 00:26:21 +02:00
Justin M. Keyes
f83d733318 log: log_uv_handles 2017-06-07 00:26:19 +02:00
ZyX
c2f3e361c5 *: Add comment to all C files 2017-04-19 19:11:50 +03:00
Justin M. Keyes
7e6a8310b7 log.c: align/adjust layout
New:
  2016/09/27 18:00:49 INFO  28117/tui_flush:597: ...

Old:
  2016/09/27 18:00:49 [info @ tui_flush:597] 28117 - ...
2016-09-28 03:29:55 +02:00
Justin M. Keyes
cc8a2e7aad log: Rename to $NVIM_LOG_FILE 2016-06-05 04:14:54 -04:00
ZyX
d0bd023881 log: Move log to $NVIM_LOG_FILE_PATH, falling back to the old location
Closes #3561
2016-05-31 16:36:49 +03:00
Seth Jackson
33321f2c85 config: Remove HAVE_UNISTD_H.
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.
2016-01-18 13:48:47 -05:00
Rui Abreu Ferreira
0ab4f2f18f Update USR_LOG_FILE definition. 2015-12-07 19:26:26 -05:00
Thiago de Arruda
2a0ff9f5cf log: Make logging thread-safe 2015-09-06 09:18:52 -03:00
Justin M. Keyes
7280e8c365 remove references to <sys/time.h>
Since gettimeofday() was replaced by os_time in
fb5a786bdb we do not need sys/time.h.
2015-08-24 00:27:30 -04:00
Rui Abreu Ferreira
e1f83d304d Add header guards for sys/time.h and unistd.h in log.c 2015-05-21 02:09:49 -04:00
bobtwinkles
03d47965c0 refactor: split some more functions from misc1.c
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
2015-03-24 16:13:00 -04:00
Thiago de Arruda
64844b7312 msgpack-rpc: Improve logging of msgpack-rpc messages
- 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.
2014-10-23 21:46:03 -03:00
ZyX
70929f7e16 Add automatic generation of headers
- 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.
2014-06-02 11:04:17 -03:00
Eliseo Martínez
409cc138f2 Introduce nvim namespace: Fix project-local includes.
Prepend 'nvim/' in all project-local (non-system) includes.
2014-05-15 20:46:01 +02:00
Eliseo Martínez
da51dc9cf2 Introduce nvim namespace: Move files.
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.
2014-05-15 20:46:01 +02:00