Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

make test: use after free: parallel/test-cli-node-options #21383

Open
matthiaskrgr opened this issue Jun 18, 2018 · 5 comments
Open

make test: use after free: parallel/test-cli-node-options #21383

matthiaskrgr opened this issue Jun 18, 2018 · 5 comments
Labels
trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events.

Comments

@matthiaskrgr
Copy link

git repo (nodejs/node) @ 64de66d
I was running CFLAGS="-fsanitize=address -fno-sanitize=leak -g3" CXXFLAGS="$CFLAGS" LDFLAGS="-fsanitize=address -fno-sanitize=leak -g3" ASAN_OPTIONS=detect_leaks=0 make test -j 4
platform: Linux t470 4.17.0-2-MANJARO #1 SMP PREEMPT Fri Jun 8 07:13:17 UTC 2018 x86_64 GNU/Linux

I used clang 6.0 as CC/CXX.

During make test, I got a use after free:

[----------] Global test environment tear-down
[==========] 74 tests from 9 test cases ran. (424 ms total)
[  PASSED  ] 74 tests.
make -s jstest
  touch 251b41f63160e3e22459f6ddaeb4fca739404752.intermediate
  touch 1b6e683759875e45877a449826f87697ec02fb35.intermediate
  LD_LIBRARY_PATH=/home/matthias/vcs/github/node/out/Release/lib.host:/home/matthias/vcs/github/node/out/Release/lib.target:$LD_LIBRARY_PATH; export LD_LIBRARY_PATH; cd ../.; mkdir -p /home/matthias/vcs/github/node/out/Release/obj/gen/src/node/inspector/protocol; python deps/v8/third_party/inspector_protocol/CodeGenerator.py --jinja_dir deps/v8/third_party/inspector_protocol/.. --output_base "/home/matthias/vcs/github/node/out/Release/obj/gen/src/" --config "/home/matthias/vcs/github/node/out/Release/obj/gen/node_protocol_config.json"
  LD_LIBRARY_PATH=/home/matthias/vcs/github/node/out/Release/lib.host:/home/matthias/vcs/github/node/out/Release/lib.target:$LD_LIBRARY_PATH; export LD_LIBRARY_PATH; cd ../deps/v8/gypfiles; mkdir -p /home/matthias/vcs/github/node/out/Release/obj/gen/src/inspector/protocol /home/matthias/vcs/github/node/out/Release/obj/gen/include/inspector; python ../third_party/inspector_protocol/CodeGenerator.py --jinja_dir ../third_party --output_base "/home/matthias/vcs/github/node/out/Release/obj/gen/src/inspector" --config ../src/inspector/inspector_protocol_config.json
=== release test-cli-node-options ===
Path: parallel/test-cli-node-options
assert.js:671
    throw newErr;
    ^
AssertionError [ERR_ASSERTION]: ifError got unwanted exception: Command failed: /home/matthias/vcs/github/node/out/Release/node -e console.log("B")
=================================================================
==25285==ERROR: AddressSanitizer: heap-use-after-free on address 0x619500000ae0 at pc 0x000001a219ac bp 0x7f46b37fed10 sp 0x7f46b37fed08
READ of size 8 at 0x619500000ae0 thread T1
    #0 0x1a219ab in uv__run_closing_handles /home/matthias/vcs/github/node/out/../deps/uv/src/unix/core.c:299:12
    #1 0x1a219ab in uv_run /home/matthias/vcs/github/node/out/../deps/uv/src/unix/core.c:370
    #2 0x7f46b6490074 in start_thread (/usr/lib/libpthread.so.0 0x7074)
    #3 0x7f46b5fad53e in __GI___clone (/usr/lib/libc.so.6 0xf853e)
0x619500000ae0 is located 96 bytes inside of 952-byte region [0x619500000a80,0x619500000e38)
freed by thread T0 here:
    #0 0x16cbbe2 in operator delete(void*) /home/matthias/LLVM/LLVM6/stage_2/llvm/projects/compiler-rt/lib/asan/asan_new_delete.cc:149:3
    #1 0x18f762d in std::default_delete<node::tracing::AsyncTraceWriter>::operator()(node::tracing::AsyncTraceWriter*) const /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/unique_ptr.h:81:2
    #2 0x18f762d in std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> >::~unique_ptr() /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/unique_ptr.h:274
    #3 0x18f762d in std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >::~pair() /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/stl_pair.h:198
    #4 0x18f762d in void __gnu_cxx::new_allocator<std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false> >::destroy<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > >(std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >*) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/ext/new_allocator.h:140
    #5 0x18f762d in void std::allocator_traits<std::allocator<std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false> > >::destroy<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > >(std::allocator<std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false> >&, std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >*) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/alloc_traits.h:487
    #6 0x18f762d in std::__detail::_Hashtable_alloc<std::allocator<std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false> > >::_M_deallocate_node(std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false>*) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/hashtable_policy.h:2100
    #7 0x18f762d in std::_Hashtable<int, std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, std::allocator<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::_M_erase(unsigned long, std::__detail::_Hash_node_base*, std::__detail::_Hash_node<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, false>*) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/hashtable.h:1905
    #8 0x18f762d in std::_Hashtable<int, std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, std::allocator<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::_M_erase(std::integral_constant<bool, true>, int const&) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/hashtable.h:1931
    #9 0x18f762d in std::_Hashtable<int, std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > >, std::allocator<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > >, std::__detail::_Select1st, std::equal_to<int>, std::hash<int>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::erase(int const&) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/hashtable.h:771
    #10 0x18f762d in std::unordered_map<int, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> >, std::hash<int>, std::equal_to<int>, std::allocator<std::pair<int const, std::unique_ptr<node::tracing::AsyncTraceWriter, std::default_delete<node::tracing::AsyncTraceWriter> > > > >::erase(int const&) /usr/lib64/gcc/x86_64-pc-linux-gnu/8.1.1/../../../../include/c  /8.1.1/bits/unordered_map.h:818
    #11 0x18f762d in node::tracing::Agent::Disconnect(int) /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:100
    #12 0x18fb9a8 in node::tracing::Agent::DisconnectClient(std::pair<node::tracing::Agent*, int>*) /home/matthias/vcs/github/node/out/../src/tracing/agent.h:67:22
    #13 0x1770792 in node::$_0::StopTracingAgent() /home/matthias/vcs/github/node/out/../src/node.cc:334:23
    #14 0x1770792 in node::Start(int, char**) /home/matthias/vcs/github/node/out/../src/node.cc:3684
    #15 0x7f46b5ed806a in __libc_start_main (/usr/lib/libc.so.6 0x2306a)
previously allocated by thread T0 here:
    #0 0x16cb002 in operator new(unsigned long) /home/matthias/LLVM/LLVM6/stage_2/llvm/projects/compiler-rt/lib/asan/asan_new_delete.cc:92:3
    #1 0x18f93bf in node::tracing::Agent::Enable(std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&) /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:137:9
    #2 0x18f857c in node::tracing::Agent::Enable(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:120:3
    #3 0x1770699 in node::$_0::StartTracingAgent() /home/matthias/vcs/github/node/out/../src/node.cc:329:21
    #4 0x1770699 in node::$_0::Initialize(int) /home/matthias/vcs/github/node/out/../src/node.cc:294
    #5 0x1770699 in node::Start(int, char**) /home/matthias/vcs/github/node/out/../src/node.cc:3678
    #6 0x7f46b5ed806a in __libc_start_main (/usr/lib/libc.so.6 0x2306a)
Thread T1 created by T0 here:
    #0 0x168601d in __interceptor_pthread_create /home/matthias/LLVM/LLVM6/stage_2/llvm/projects/compiler-rt/lib/asan/asan_interceptors.cc:204:3
    #1 0x1a4755b in uv_thread_create /home/matthias/vcs/github/node/out/../deps/uv/src/unix/thread.c:202:9
    #2 0x18f62de in node::tracing::Agent::Start() /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:65:3
    #3 0x18f93b5 in node::tracing::Agent::Enable(std::set<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >, std::less<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > >, std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > > > const&) /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:135:5
    #4 0x18f857c in node::tracing::Agent::Enable(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) /home/matthias/vcs/github/node/out/../src/tracing/agent.cc:120:3
    #5 0x1770699 in node::$_0::StartTracingAgent() /home/matthias/vcs/github/node/out/../src/node.cc:329:21
    #6 0x1770699 in node::$_0::Initialize(int) /home/matthias/vcs/github/node/out/../src/node.cc:294
    #7 0x1770699 in node::Start(int, char**) /home/matthias/vcs/github/node/out/../src/node.cc:3678
    #8 0x7f46b5ed806a in __libc_start_main (/usr/lib/libc.so.6 0x2306a)
SUMMARY: AddressSanitizer: heap-use-after-free /home/matthias/vcs/github/node/out/../deps/uv/src/unix/core.c:299:12 in uv__run_closing_handles
Shadow bytes around the buggy address:
  0x0c327fff8100: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c327fff8110: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c327fff8120: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c327fff8130: 00 00 00 00 00 fa fa fa fa fa fa fa fa fa fa fa
  0x0c327fff8140: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
=>0x0c327fff8150: fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd fd fd
  0x0c327fff8160: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff8170: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff8180: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff8190: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c327fff81a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
==25285==ABORTING
    at ChildProcess.exithandler (child_process.js:291:12)
    at ChildProcess.emit (events.js:182:13)
    at maybeClose (internal/child_process.js:961:16)
    at Process.ChildProcess._handle.onexit (internal/child_process.js:248:5)
Command: out/Release/node /home/matthias/vcs/github/node/test/parallel/test-cli-node-options.js
=== release test-crypto-dh-leak ===
Path: parallel/test-crypto-dh-leak
assert.js:270
    throw err;
    ^
AssertionError [ERR_ASSERTION]: before=131252224 after=150888448
    at Object.<anonymous> (/home/matthias/vcs/github/node/test/parallel/test-crypto-dh-leak.js:26:1)
    at Module._compile (internal/modules/cjs/loader.js:702:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:713:10)
    at Module.load (internal/modules/cjs/loader.js:612:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:551:12)
    at Function.Module._load (internal/modules/cjs/loader.js:543:3)
    at Function.Module.runMain (internal/modules/cjs/loader.js:744:10)
    at startup (internal/bootstrap/node.js:241:19)
    at bootstrapNodeJSCore (internal/bootstrap/node.js:565:3)
Command: out/Release/node --expose-gc --noconcurrent_recompilation /home/matthias/vcs/github/node/test/parallel/test-crypto-dh-leak.js
@matthiaskrgr matthiaskrgr changed the title make test: use after free make test: use after free: parallel/test-cli-node-options Jun 18, 2018
@bnoordhuis
Copy link
Member

cc @eugeneo @ofrobots - I'm reasonably sure this is caused by freeing the memory of one of the uv_async_t handles prematurely.

At a guess, the signalling from the close callback needs to be delayed until both close callbacks have happened (applies to both node_trace_buffer.cc and node_trace_writer.cc.)

@bnoordhuis bnoordhuis added the trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events. label Jun 18, 2018
@eugeneo
Copy link
Contributor

eugeneo commented Jun 18, 2018

I think #21335 should fix it.

@Trott
Copy link
Member

Trott commented Nov 25, 2018 •
edited
Loading

#21335 was closed without landing. Did an alternative land? Should this be closed?

If this is still a problem, might it be the source of this that comes up in CI on Windows 10:

00:57:06 not ok 71 parallel/test-cli-node-options
00:57:06   ---
00:57:06   duration_ms: 2.627
00:57:06   severity: fail
00:57:06   exitcode: 1
00:57:06   stack: |-
00:57:06     assert.js:753
00:57:06         throw newErr;
00:57:06         ^
00:57:06     
00:57:06     AssertionError [ERR_ASSERTION]: ifError got unwanted exception: Command failed: c:\workspace\node-test-binary-windows\Release\node.exe -e console.log("B")
00:57:06     
00:57:06         at ChildProcess.exithandler (child_process.js:294:12)
00:57:06         at ChildProcess.emit (events.js:189:13)
00:57:06         at maybeClose (internal/child_process.js:977:16)
00:57:06         at Process.ChildProcess._handle.onexit (internal/child_process.js:265:5)
00:57:06   ...

Above is from https://ci.nodejs.org/job/node-test-binary-windows/21941/COMPILED_BY=vs2017,RUNNER=win10,RUN_SUBSET=0/console and was on host test-azure_msft-win10-x64-4.

@Trott Trott mentioned this issue Dec 14, 2018
Closed
@jasnell
Copy link
Member

jasnell commented Jun 26, 2020

@nodejs/build Has this been resolved?

@richardlau
Copy link
Member

@nodejs/build Has this been resolved?

¯\_(ツ)_/¯ This doesn't look like a build issue. It looks like it was an issue with trace events.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
trace_events Issues and PRs related to V8, Node.js core, and userspace code trace events.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@bnoordhuis @eugeneo @jasnell @matthiaskrgr @Trott @richardlau