channels: fix use after free #7813

bfredl · 2018-01-05T20:38:13Z

Ref #7699 (comment). I will add test tomorrow.

justinmk · 2018-01-07T09:34:48Z

src/nvim/channel.c


  if ((--chan->refcount != 0)) {
    abort();
  }

-  free_channel_event((void **)&chan);
+  // uv will still keep a reference to our memory until next event loop tick, so delay free
+  multiqueue_put(main_loop.fast_events, free_channel_event, 1, chan);


libuv resources should be freed in their respective "on close" handlers. Is that the problem?

I think it can be assumed that libuv frees handles at latest during the next loop iteration (but not in the middle of a still ongoing tick). Otherwise we will need to keep a second refcount on the channel struct just for "number of not yet closed libuv handles"

bfredl · 2018-01-07T10:45:05Z

Actually closing pipes was not problematic, only the process handle itself (uv_spawn only "activates" the handle if the process spawned succesfully).

What I think we really need is to defer freeing the channel struct until after a uv loop iteration. fast_events is not good enough as it is a child-queue of the main queue, which can be processed before uv loop is invoked (and not after as in loop_poll_events). I ended up using loop_schedule, this does what we want except that it is also thread-safe, but for now it is probably not worth adding a copy that avoids the mutex.

I get one remaining failure in luaeval(vim.api.…) errors out correctly when working with API, not sure if it is directly libuv related or just ASAN being able to detect a new existing error.

[ RUN      ] luaeval(vim.api.…) errors out correctly when working with API: -- Output to stderr:
=================================================================
==18355==AddressSanitizer CHECK failed: /build/llvm/src/llvm-5.0.0.src/projects/compiler-rt/lib/asan/asan_thread.cc:327 "((ptr[0] == kCurrentStackFrameMagic)) != (0)" (0x0, 0x0)
    #0 0x55a98e372077 in __asan::AsanCheckFailed(char const*, int, char const*, unsigned long long, unsigned long long) (/home/bjorn/dev/neovim/build/bin/nvim+0xa3d077)
    #1 0x55a98e38ed45 in __sanitizer::CheckFailed(char const*, int, char const*, unsigned long long, unsigned long long) (/home/bjorn/dev/neovim/build/bin/nvim+0xa59d45)
    #2 0x55a98e376e4e in __asan::AsanThread::GetStackFrameAccessByAddr(unsigned long, __asan::AsanThread::StackFrameAccess*) (/home/bjorn/dev/neovim/build/bin/nvim+0xa41e4e)
    #3 0x55a98e2b6f28 in __asan::AddressDescription::AddressDescription(unsigned long, unsigned long, bool) (/home/bjorn/dev/neovim/build/bin/nvim+0x981f28)
    #4 0x55a98e2b9770 in __asan::ErrorGeneric::ErrorGeneric(unsigned int, unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long) (/home/bjorn/dev/neovim/build/bin/nvim+0x984770)
    #5 0x55a98e37195e in __asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool) (/home/bjorn/dev/neovim/build/bin/nvim+0xa3c95e)
    #6 0x55a98e3726d8 in __asan_report_load8 (/home/bjorn/dev/neovim/build/bin/nvim+0xa3d6d8)
    #7 0x55a98f519a09 in vim_vsnprintf /home/bjorn/dev/neovim/build/../src/nvim/strings.c:941:31
    #8 0x55a98edb18e6 in emsgfv /home/bjorn/dev/neovim/build/../src/nvim/message.c:604:3
    #9 0x55a98edb17c5 in emsgf /home/bjorn/dev/neovim/build/../src/nvim/message.c:590:9
    #10 0x55a98ec7c955 in nlua_error /home/bjorn/dev/neovim/build/../src/nvim/lua/executor.c:113:3
    #11 0x55a98ec7d4e4 in nlua_eval_lua_string /home/bjorn/dev/neovim/build/../src/nvim/lua/executor.c:434:5
    #12 0x55a98f9f89f6 in lj_BC_JFUNCV (/home/bjorn/dev/neovim/build/bin/nvim+0x20c39f6)
    #13 0x55a98ec7cb89 in executor_eval_lua /home/bjorn/dev/neovim/build/../src/nvim/lua/executor.c:620:3
    #14 0x55a98e72eed6 in f_luaeval /home/bjorn/dev/neovim/build/../src/nvim/eval.c:12129:3
    #15 0x55a98e658529 in call_func /home/bjorn/dev/neovim/build/../src/nvim/eval.c:6389:11
    #16 0x55a98e66c3d0 in get_func_tv /home/bjorn/dev/neovim/build/../src/nvim/eval.c:6136:11
    #17 0x55a98e665280 in ex_call /home/bjorn/dev/neovim/build/../src/nvim/eval.c:2751:9
    #18 0x55a98e979396 in do_one_cmd /home/bjorn/dev/neovim/build/../src/nvim/ex_docmd.c:2242:5
    #19 0x55a98e95c435 in do_cmdline /home/bjorn/dev/neovim/build/../src/nvim/ex_docmd.c:609:20
    #20 0x55a98e6a9737 in ex_execute /home/bjorn/dev/neovim/build/../src/nvim/eval.c:19440:7
    #21 0x55a98e979396 in do_one_cmd /home/bjorn/dev/neovim/build/../src/nvim/ex_docmd.c:2242:5
    #22 0x55a98e95c435 in do_cmdline /home/bjorn/dev/neovim/build/../src/nvim/ex_docmd.c:609:20
    #23 0x55a98e9623a5 in do_cmdline_cmd /home/bjorn/dev/neovim/build/../src/nvim/ex_docmd.c:280:10
    #24 0x55a98e4908be in nvim_command /home/bjorn/dev/neovim/build/../src/nvim/api/vim.c:55:3
    #25 0x55a98e3f72f8 in handle_nvim_command /home/bjorn/dev/neovim/build/src/nvim/auto/api/private/dispatch_wrappers.generated.h:1616:3
    #26 0x55a98ee5bff5 in on_request_event /home/bjorn/dev/neovim/build/../src/nvim/msgpack_rpc/channel.c:361:19
    #27 0x55a98e883ded in multiqueue_process_events /home/bjorn/dev/neovim/build/../src/nvim/event/multiqueue.c:150:7
    #28 0x55a98ef111b6 in nv_event /home/bjorn/dev/neovim/build/../src/nvim/normal.c:7965:3
    #29 0x55a98eec25a2 in normal_execute /home/bjorn/dev/neovim/build/../src/nvim/normal.c:1136:3
    #30 0x55a98f50fbae in state_enter /home/bjorn/dev/neovim/build/../src/nvim/state.c:67:26
    #31 0x55a98ee81898 in normal_enter /home/bjorn/dev/neovim/build/../src/nvim/normal.c:466:3
    #32 0x55a98ec84e63 in main /home/bjorn/dev/neovim/build/../src/nvim/main.c:572:3
    #33 0x7fa4fc3daf69 in __libc_start_main (/usr/lib/libc.so.6+0x20f69)
    #34 0x55a98e2a8b79 in _start (/home/bjorn/dev/neovim/build/bin/nvim+0x973b79)

bfredl · 2018-01-07T10:48:44Z

Also deps caching or something prevents libuv from being built with ASAN on travis. Though the current implementation is a hard-coded hack, I might need help from someone more familiar with our ci code. Modulo fixing the remaining luajit related error, I think we would want it to make incorrect libuv use fail quicker.

jamessan · 2018-01-07T12:37:30Z

That luaeval ASAN failure looks like #6774, which is an upstream problem.

justinmk · 2018-01-21T15:35:25Z

Unusual output from log_uv_handles(): https://gist.github.com/justinmk/802fc6f6343658358a3d623b626d46dc

===============================================================================
NVIM_LOG_FILE: /home/travis/build/neovim/neovim/build/.nvimlog
[--I] signal   0x30f96c8
[-AI] async    0x30f9510
[RA-] async    0x30f99a0
[R--] signal 0x30f97d0
<...much more...>

bfredl · 2018-01-24T17:58:09Z

I was just testing if log_uv_handles would crash in general (it was behind an if() before), but it seems not to...

bfredl · 2018-01-28T10:43:56Z

Hmm, the scrollbind test doesn't fail if I run it (still on ASAN travis) in isolation. The failure is weird anyway as scrollbind doesn't use any channels or any other IO except ordinary buffer load/save...

justinmk · 2018-04-12T16:20:44Z

@bfredl is this ready? LGTM

bfredl · 2018-04-12T16:21:35Z

@justinmk Let me squash it and cycle travis a few times...

add test for a crash this caused

closes neovim#8813 ref neovim#7813 (comment) ref neovim#8088 (comment) Sometimes ASan fails like this: = ==16820==ERROR: AddressSanitizer: SEGV on unknown address 0x000001baab50 (pc 0x00000044f3a1 bp 0x000000000001 sp 0x7fff7ddb6a60 T0) ... = 4 0xfbfae4 in xfree /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:134:3 = 5 0x120e948 in free_string_option /home/travis/build/neovim/neovim/build/../src/nvim/option.c:2207:5 = 6 0x120de3d in free_all_options /home/travis/build/neovim/neovim/build/../src/nvim/option.c:923:9 = 7 0xfc2441 in free_all_mem /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:622:3 = 8 0x12bbe6c in mch_exit /home/travis/build/neovim/neovim/build/../src/nvim/os_unix.c:153:3 = 9 0x1092cc3 in exit_event /home/travis/build/neovim/neovim/build/../src/nvim/msgpack_rpc/channel.c:542:5 = 10 0xa6b2d3 in multiqueue_process_events /home/travis/build/neovim/neovim/build/../src/nvim/event/multiqueue.c:150:7 = 11 0xa64e2f in loop_poll_events /home/travis/build/neovim/neovim/build/../src/nvim/event/loop.c:65:3 = 12 0x12a4ec0 in os_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/os/input.c:162:5 = 13 0x1035f07 in line_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/misc1.c:2692:5 ... = 19 0x137ac07 in vim_regexec_nl /home/travis/build/neovim/neovim/build/../src/nvim/regexp.c:7302:10 = 20 0x910f2b in f_split /home/travis/build/neovim/neovim/build/../src/nvim/eval.c:15673:17 ... = 43 0x11667d5 in normal_check /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:1325:5 = 44 0x17774c1 in state_enter /home/travis/build/neovim/neovim/build/../src/nvim/state.c:28:35 = 45 0x10c0bf4 in normal_enter /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:467:3 = 46 0xea98a2 in main /home/travis/build/neovim/neovim/build/../src/nvim/main.c:566:3 = 47 0x7fbb0a667f44 in __libc_start_main /build/eglibc-ripdx6/eglibc-2.19/csu/libc-start.c:287 = 48 0x44e39b in _start (/home/travis/build/neovim/neovim/build/bin/nvim+0x44e39b) ===================================================================================================== test/helpers.lua:149: assertion failed! Discussion: - `free_all_options` is free'ing something before it was alloc'd. - ~~Options init isn't complete?~~ (No: init completed, `main.c` reached `normal_enter()`) - stdio RPC channel was closed (so `rpc_close` schedules `exit_event`) - was this because the client died from a invalid message? - `exit_event` is scheduled on `main_loop.fast_events`. - would `main_loop.events` defer it? Or do we need something like `stuffReadbuff(":qall!\n")`?

closes neovim#8813 ref neovim#7813 (comment) ref neovim#8088 (comment) Sometimes ASan fails like this: = ==16820==ERROR: AddressSanitizer: SEGV on unknown address 0x000001baab50 (pc 0x00000044f3a1 bp 0x000000000001 sp 0x7fff7ddb6a60 T0) ... 4 0xfbfae4 in xfree /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:134:3 5 0x120e948 in free_string_option /home/travis/build/neovim/neovim/build/../src/nvim/option.c:2207:5 6 0x120de3d in free_all_options /home/travis/build/neovim/neovim/build/../src/nvim/option.c:923:9 7 0xfc2441 in free_all_mem /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:622:3 8 0x12bbe6c in mch_exit /home/travis/build/neovim/neovim/build/../src/nvim/os_unix.c:153:3 9 0x1092cc3 in exit_event /home/travis/build/neovim/neovim/build/../src/nvim/msgpack_rpc/channel.c:542:5 10 0xa6b2d3 in multiqueue_process_events /home/travis/build/neovim/neovim/build/../src/nvim/event/multiqueue.c:150:7 11 0xa64e2f in loop_poll_events /home/travis/build/neovim/neovim/build/../src/nvim/event/loop.c:65:3 12 0x12a4ec0 in os_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/os/input.c:162:5 13 0x1035f07 in line_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/misc1.c:2692:5 ... 19 0x137ac07 in vim_regexec_nl /home/travis/build/neovim/neovim/build/../src/nvim/regexp.c:7302:10 20 0x910f2b in f_split /home/travis/build/neovim/neovim/build/../src/nvim/eval.c:15673:17 ... 43 0x11667d5 in normal_check /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:1325:5 44 0x17774c1 in state_enter /home/travis/build/neovim/neovim/build/../src/nvim/state.c:28:35 45 0x10c0bf4 in normal_enter /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:467:3 46 0xea98a2 in main /home/travis/build/neovim/neovim/build/../src/nvim/main.c:566:3 47 0x7fbb0a667f44 in __libc_start_main /build/eglibc-ripdx6/eglibc-2.19/csu/libc-start.c:287 48 0x44e39b in _start (/home/travis/build/neovim/neovim/build/bin/nvim+0x44e39b) Discussion: - `free_all_options` is free'ing something before it was alloc'd. - ~~Options init isn't complete?~~ (No: init completed, `main.c` reached `normal_enter()`) - stdio RPC channel was closed (so `rpc_close` schedules `exit_event`) - was this because the client died from a invalid message? - `exit_event` is scheduled on `main_loop.fast_events`. - would `main_loop.events` defer it? Or do we need something like `stuffReadbuff(":qall!\n")`? Deferring the event: diff --git a/src/nvim/msgpack_rpc/channel.c b/src/nvim/msgpack_rpc/channel.c index 3244d83..62c7717 100644 --- a/src/nvim/msgpack_rpc/channel.c +++ b/src/nvim/msgpack_rpc/channel.c @@ -532,7 +532,7 @@ void rpc_close(Channel *channel) channel_decref(channel); if (channel->streamtype == kChannelStreamStdio) { - multiqueue_put(main_loop.fast_events, exit_event, 0); + multiqueue_put(main_loop.events, exit_event, 0); } } ...leads to hangs (waiting for input): [5/7] Building C object test/functiona...s/CMakeFiles/tty-test.dir/tty-test.c.o�[K [6/7] Linking C executable bin/tty-test�[K [6/7] Linking C executable bin/tty-test�[K [7/7] cd /home/travis/build/neovim/neo...ild/neovim/neovim/cmake/RunTests.cmake�[K No output has been received in the last 10m0s, this potentially indicates a stalled build or something wrong with the build itself. Check the details on how to adjust your build configuration on: https://docs.travis-ci.com/user/common-build-problems/#Build-times-out-because-no-output-was-received The build has been terminated

closes neovim#8813 ref neovim#7813 (comment) ref neovim#8088 (comment) Sometimes ASan fails like this: = ==16820==ERROR: AddressSanitizer: SEGV on unknown address 0x000001baab50 (pc 0x00000044f3a1 bp 0x000000000001 sp 0x7fff7ddb6a60 T0) ... 4 0xfbfae4 in xfree /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:134:3 5 0x120e948 in free_string_option /home/travis/build/neovim/neovim/build/../src/nvim/option.c:2207:5 6 0x120de3d in free_all_options /home/travis/build/neovim/neovim/build/../src/nvim/option.c:923:9 7 0xfc2441 in free_all_mem /home/travis/build/neovim/neovim/build/../src/nvim/memory.c:622:3 8 0x12bbe6c in mch_exit /home/travis/build/neovim/neovim/build/../src/nvim/os_unix.c:153:3 9 0x1092cc3 in exit_event /home/travis/build/neovim/neovim/build/../src/nvim/msgpack_rpc/channel.c:542:5 10 0xa6b2d3 in multiqueue_process_events /home/travis/build/neovim/neovim/build/../src/nvim/event/multiqueue.c:150:7 11 0xa64e2f in loop_poll_events /home/travis/build/neovim/neovim/build/../src/nvim/event/loop.c:65:3 12 0x12a4ec0 in os_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/os/input.c:162:5 13 0x1035f07 in line_breakcheck /home/travis/build/neovim/neovim/build/../src/nvim/misc1.c:2692:5 ... 19 0x137ac07 in vim_regexec_nl /home/travis/build/neovim/neovim/build/../src/nvim/regexp.c:7302:10 20 0x910f2b in f_split /home/travis/build/neovim/neovim/build/../src/nvim/eval.c:15673:17 ... 43 0x11667d5 in normal_check /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:1325:5 44 0x17774c1 in state_enter /home/travis/build/neovim/neovim/build/../src/nvim/state.c:28:35 45 0x10c0bf4 in normal_enter /home/travis/build/neovim/neovim/build/../src/nvim/normal.c:467:3 46 0xea98a2 in main /home/travis/build/neovim/neovim/build/../src/nvim/main.c:566:3 47 0x7fbb0a667f44 in __libc_start_main /build/eglibc-ripdx6/eglibc-2.19/csu/libc-start.c:287 48 0x44e39b in _start (/home/travis/build/neovim/neovim/build/bin/nvim+0x44e39b) Discussion: - `free_all_options` is free'ing something before it was alloc'd. - ~~Options init isn't complete?~~ (No: init completed, `main.c` reached `normal_enter()`) - stdio RPC channel was closed (so `rpc_close` schedules `exit_event`) - was this because the client died from a invalid message? - `exit_event` is scheduled on `main_loop.fast_events`. - would `main_loop.events` defer it? Or do we need something like `stuffReadbuff(":qall!\n")`?

marvim added the WIP label Jan 5, 2018

bfredl mentioned this pull request Jan 6, 2018

[IGNORE] run use after free test on travis master #7816

Closed

bfredl force-pushed the chanfree branch from 98a618a to 7ede6df Compare January 6, 2018 09:54

This comment was marked as outdated.

Sign in to view

justinmk reviewed Jan 7, 2018

View reviewed changes

bfredl force-pushed the chanfree branch from 7550c3b to f71ac9c Compare January 7, 2018 10:35

bfredl force-pushed the chanfree branch from f71ac9c to dfdc848 Compare January 7, 2018 18:13

bfredl mentioned this pull request Jan 11, 2018

api: change nvim_command_output behavior #7821

Merged

justinmk mentioned this pull request Jan 12, 2018

neovim randomly crashing with ALE #7768

Closed

bfredl force-pushed the chanfree branch from dfdc848 to 6ee53a0 Compare January 21, 2018 08:25

justinmk added this to the 0.2.3 milestone Jan 21, 2018

bfredl force-pushed the chanfree branch from 3946849 to 23f0db3 Compare January 24, 2018 17:57

bfredl force-pushed the chanfree branch from 77366e7 to d066ab9 Compare January 28, 2018 10:44

bfredl force-pushed the chanfree branch from e42d1b6 to 3078155 Compare February 24, 2018 13:08

bfredl force-pushed the chanfree branch from 3078155 to 57fd8e3 Compare March 5, 2018 18:43

bfredl force-pushed the chanfree branch 3 times, most recently from ffaf71e to 0e95b22 Compare March 24, 2018 08:09

channels: delay free so that libuv can cleanup handles

aea079a

add test for a crash this caused

bfredl force-pushed the chanfree branch from 2ca1c6f to 453b8aa Compare April 12, 2018 16:25

channels: cleanup channel freeing code

0865adb

bfredl force-pushed the chanfree branch from 453b8aa to 0865adb Compare April 12, 2018 20:35

This comment was marked as outdated.

Sign in to view

justinmk changed the title ~~[WIP] channels: fix use after free~~ channels: fix use after free Apr 12, 2018

justinmk merged commit 5e18550 into neovim:master Apr 12, 2018

justinmk removed the WIP label Apr 12, 2018

justinmk mentioned this pull request May 6, 2018

test: fix quickbuild #8368

Closed

justinmk mentioned this pull request Aug 4, 2018

teardown: race between options setup and exit_event #8813

Open

justinmk mentioned this pull request Aug 5, 2018

channel.c: defer exit_event #8814

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Uh oh!

channels: fix use after free #7813

channels: fix use after free #7813

Uh oh!

bfredl commented Jan 5, 2018 •

edited

Loading

Uh oh!

This comment was marked as outdated.

justinmk Jan 7, 2018 •

edited

Loading

Uh oh!

bfredl Jan 7, 2018 •

edited

Loading

Uh oh!

bfredl commented Jan 7, 2018

Uh oh!

bfredl commented Jan 7, 2018

Uh oh!

jamessan commented Jan 7, 2018

Uh oh!

justinmk commented Jan 21, 2018

Uh oh!

bfredl commented Jan 24, 2018

Uh oh!

bfredl commented Jan 28, 2018

Uh oh!

justinmk commented Apr 12, 2018 •

edited

Loading

Uh oh!

bfredl commented Apr 12, 2018

Uh oh!

This comment was marked as outdated.

Uh oh!

Uh oh!

channels: fix use after free #7813

channels: fix use after free #7813

Uh oh!

Conversation

bfredl commented Jan 5, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

This comment was marked as outdated.

justinmk Jan 7, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

bfredl Jan 7, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

bfredl commented Jan 7, 2018

Uh oh!

bfredl commented Jan 7, 2018

Uh oh!

jamessan commented Jan 7, 2018

Uh oh!

justinmk commented Jan 21, 2018

Uh oh!

bfredl commented Jan 24, 2018

Uh oh!

bfredl commented Jan 28, 2018

Uh oh!

justinmk commented Apr 12, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

bfredl commented Apr 12, 2018

Uh oh!

This comment was marked as outdated.

Uh oh!

bfredl commented Jan 5, 2018 •

edited

Loading

justinmk Jan 7, 2018 •

edited

Loading

bfredl Jan 7, 2018 •

edited

Loading

justinmk commented Apr 12, 2018 •

edited

Loading