Commit Graph

17 Commits

Author SHA1 Message Date
Justin M. Keyes
dbba685c69 build: include auto/config.h explicitly
Otherwise the symbols defined in config/config.h.in may not be defined,
depending on include-order.
2019-01-20 00:18:39 +01:00
Justin M. Keyes
b9bcfa9bc8 log: rename do_log to logmsg 2018-09-19 00:58:25 +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
Yichao Zhou
5fc775e2ef log.h: LOG_CALLSTACK 2017-07-23 17:02:06 +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
Florian Walch
cb87ea7e82 CMake: Disable logging for release build types.
These are: Release, MinSizeRel, and RelWithDebInfo.

Closes #2913.
2015-11-01 15:41:36 +01: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
Thiago de Arruda
cf30837951 api/events/msgpack: Insert log statements to improve debugging
Also changed the default log level to INFO so developers won't end up with big
log files without asking explicitly(DLOG statements were placed in really "hot"
code)
2014-07-17 11:37:41 -03:00
ZyX
a7e3c4f6f6 Remove a number of unneeded func_attr includes 2014-06-02 11:04:18 -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
5f795225dc Introduce nvim namespace: Fix define guards.
Change define guards from NEOVIM_XXX_H to NVIM_XXX_H:
- Change header files.
- Change clint correct guard name calculation.
2014-05-15 20:46:02 +02: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