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.

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

Running node from udev causes SEGV #16901

Closed
IIIMADDINIII opened this issue Nov 9, 2017 · 10 comments
Closed

Running node from udev causes SEGV #16901

IIIMADDINIII opened this issue Nov 9, 2017 · 10 comments
Labels
v8 engine Issues and PRs related to the V8 dependency.

Comments

@IIIMADDINIII
Copy link

I tried to run node from a udev rule. When testing the rule with "udevadm test" node gets executed and doesn't fail. When testing the rule with "udevadm trigger" node terminates with the signal SEGV. This also happens if a device is attached.

I have tried with the following two lines in the udev rule file. Both result in the same SEGV error.

IMPORT{program}="/home/maddin/node/bin/node"
RUN+="/home/maddin/node/bin/node"

After a device is attached the syslog shows the following (node 9.1.0):

Nov  9 11:25:26 YouBuntToo kernel: [ 2628.227653] node[21476]: segfault at f ip 0000000001051c80 sp 00007ffe0d95a510 error 6 in node[400000+1b5e000]
Nov  9 11:25:26 YouBuntToo kernel: [ 2628.343509] node[21485]: segfault at f ip 0000000001051c80 sp 00007ffd716f1900 error 6 in node[400000+1b5e000]
Nov  9 11:25:26 YouBuntToo kernel: [ 2628.344796] node[21488]: segfault at f ip 0000000001051c80 sp 00007ffe1b934770 error 6 in node[400000+1b5e000]
Nov  9 11:25:26 YouBuntToo kernel: [ 2628.345274] node[21484]: segfault at f ip 0000000001051c80 sp 00007ffe98e586e0 error 6 in node[400000+1b5e000]
Nov  9 11:25:26 YouBuntToo kernel: [ 2628.347731] node[21490]: segfault at f ip 0000000001051c80 sp 00007ffd480438a0 error 6 in node[400000+1b5e000]
Nov  9 11:25:26 YouBuntToo systemd-udevd[21462]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo systemd-udevd[21463]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo systemd-udevd[21462]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo systemd-udevd[21483]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo systemd-udevd[21482]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo kernel: [ 2628.496177] node[21535]: segfault at f ip 0000000001051c80 sp 00007ffeecbd65f0 error 6 in node[400000+1b5e000]
Nov  9 11:25:27 YouBuntToo systemd-udevd[21486]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo kernel: [ 2628.723731] node[21565]: segfault at f ip 0000000001051c80 sp 00007ffe1cefeb20 error 6 in node[400000+1b5e000]
Nov  9 11:25:27 YouBuntToo kernel: [ 2628.765871] node[21577]: segfault at f ip 0000000001051c80 sp 00007ffc8e5bcc60 error 6 in node[400000+1b5e000]
Nov  9 11:25:27 YouBuntToo systemd-udevd[21462]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.
Nov  9 11:25:27 YouBuntToo systemd-udevd[21486]: Process '/home/maddin/node/bin/node' terminated by signal SEGV.

With node 8.9.1 the address 0000000001051c80 changes to 0000000001087f90.

@bnoordhuis
Copy link
Member

Can you get a stack trace? What script are you trying to run?

@IIIMADDINIII
Copy link
Author

It fails independently of the script. At the moment iI define no script so node runs in REPL mode. Even if I define a script if fails exactly the same. I tried an empty script and a non empty script.
How can i make a stack trace?

@bnoordhuis
Copy link
Member

Turn on core dumps and inspect the core file in gdb afterwards (thread apply all bt full; disassemble and info registers are helpful too.)

@IIIMADDINIII
Copy link
Author

After a long google search I have got the core dump working. I am new to debugging in Linux, thanks for this info. I have attached the core dump file for node v9.1.0. The following results are also from node v9.1.0.

backtrace:

#0  0x0000000001051c80 in v8::internal::RegExpResultsCache::Clear(v8::internal::FixedArray*) ()
#1  0x0000000000e576da in v8::internal::Heap::MarkCompactPrologue() ()
#2  0x0000000000e57d9f in v8::internal::Heap::MarkCompact() ()
#3  0x0000000000e736a9 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) ()
#4  0x0000000000e74578 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [clone .constprop.934] ()
#5  0x0000000000e750fc in v8::internal::Heap::ReserveSpace(std::vector<v8::internal::Heap::Chunk, std::allocator<v8::internal::Heap::Chunk> >*, std::vector<unsigned char*, std::allocator<unsigned char*> >*) ()
#6  0x00000000010cd707 in v8::internal::Deserializer::ReserveSpace() ()
#7  0x00000000010dccce in v8::internal::StartupDeserializer::DeserializeInto(v8::internal::Isolate*) ()
#8  0x0000000000f1ab45 in v8::internal::Isolate::Init(v8::internal::StartupDeserializer*) ()
#9  0x00000000010dc391 in v8::internal::Snapshot::Initialize(v8::internal::Isolate*) ()
#10 0x0000000000af1ac8 in v8::IsolateNewImpl(v8::internal::Isolate*, v8::Isolate::CreateParams const&) ()
#11 0x00000000011f053d in node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) ()
#12 0x00000000011e9d43 in node::Start(int, char**) ()
#13 0x00007f2fc1afd1c1 in __libc_start_main (main=0x8934b0 <main>, argc=1, argv=0x7ffcd4dc65c8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffcd4dc65b8) at ../csu/libc-start.c:308
#14 0x0000000000895671 in _start ()

thread apply all bt full:

Thread 5 (Thread 0x7f2fc02d8700 (LWP 25670)):
#0  0x00007f2fc1eca072 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x24593f0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
        __ret = -512
        oldtype = 0
        err = <optimized out>
#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x24593a0, cond=0x24593c8) at pthread_cond_wait.c:502
        spin = 0
        buffer = {__routine = 0x7f2fc1ec9e00 <__condvar_cleanup_waiting>, __arg = 0x7f2fc02d7e60, __canceltype = -1, __prev = 0x0}
        cbuffer = {wseq = 0, cond = 0x24593c8, mutex = 0x24593a0, private = 0}
        err = <optimized out>
        g = 0
        flags = <optimized out>
        signals = 0
        result = 0
        seq = 0
#2  __pthread_cond_wait (cond=0x24593c8, mutex=0x24593a0) at pthread_cond_wait.c:655
No locals.
#3  0x000000000142e519 in uv_cond_wait (cond=<optimized out>, mutex=<optimized out>) at ../deps/uv/src/unix/thread.c:641
No locals.
#4  0x0000000001238a24 in node::BackgroundRunner(void*) ()
No symbol table info available.
#5  0x00007f2fc1ec37fc in start_thread (arg=0x7f2fc02d8700) at pthread_create.c:465
        pd = 0x7f2fc02d8700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139843064399616, -4286327906685610494, 140723879699182, 140723879699183, 139843064399616, 139843064400320, 4241378338042091010, 4241375600262583810}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0,
              canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#6  0x00007f2fc1bf0b0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

Thread 4 (Thread 0x7f2fc12da700 (LWP 25667)):
#0  0x00007f2fc1eca072 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x24593f0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
        __ret = -512
        oldtype = 0
        err = <optimized out>
#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x24593a0, cond=0x24593c8) at pthread_cond_wait.c:502
        spin = 0
        buffer = {__routine = 0x7f2fc1ec9e00 <__condvar_cleanup_waiting>, __arg = 0x7f2fc12d9e60, __canceltype = 0, __prev = 0x0}
        cbuffer = {wseq = 2, cond = 0x24593c8, mutex = 0x24593a0, private = 0}
        err = <optimized out>
        g = 0
        flags = <optimized out>
        signals = 0
        result = 0
        seq = 1
#2  __pthread_cond_wait (cond=0x24593c8, mutex=0x24593a0) at pthread_cond_wait.c:655
No locals.
#3  0x000000000142e519 in uv_cond_wait (cond=<optimized out>, mutex=<optimized out>) at ../deps/uv/src/unix/thread.c:641
No locals.
#4  0x0000000001238a24 in node::BackgroundRunner(void*) ()
No symbol table info available.
#5  0x00007f2fc1ec37fc in start_thread (arg=0x7f2fc12da700) at pthread_create.c:465
        pd = 0x7f2fc12da700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139843081185024, -4286327906685610494, 140723879699182, 140723879699183, 139843081185024, 139843081185728, 4241376144387544578, 4241375600262583810}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0,
              canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#6  0x00007f2fc1bf0b0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

Thread 3 (Thread 0x7f2fc1adb700 (LWP 25666)):
#0  0x00007f2fc1eca072 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x24593f0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
        __ret = -512
        oldtype = 0
        err = <optimized out>
#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x24593a0, cond=0x24593c8) at pthread_cond_wait.c:502
        spin = 0
        buffer = {__routine = 0x7f2fc1ec9e00 <__condvar_cleanup_waiting>, __arg = 0x7f2fc1adae60, __canceltype = 0, __prev = 0x0}
        cbuffer = {wseq = 6, cond = 0x24593c8, mutex = 0x24593a0, private = 0}
        err = <optimized out>
        g = 0
        flags = <optimized out>
        signals = 0
        result = 0
        seq = 3
#2  __pthread_cond_wait (cond=0x24593c8, mutex=0x24593a0) at pthread_cond_wait.c:655
No locals.
#3  0x000000000142e519 in uv_cond_wait (cond=<optimized out>, mutex=<optimized out>) at ../deps/uv/src/unix/thread.c:641
No locals.
#4  0x0000000001238a24 in node::BackgroundRunner(void*) ()
No symbol table info available.
#5  0x00007f2fc1ec37fc in start_thread (arg=0x7f2fc1adb700) at pthread_create.c:465
        pd = 0x7f2fc1adb700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139843089577728, -4286327906685610494, 140723879699182, 140723879699183, 139843089577728, 139843089578432, 4241375045412787714, 4241375600262583810}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0,
              canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
---Type <return> to continue, or q <return> to quit---
#6  0x00007f2fc1bf0b0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

Thread 2 (Thread 0x7f2fc0ad9700 (LWP 25668)):
#0  0x00007f2fc1eca072 in futex_wait_cancelable (private=<optimized out>, expected=0, futex_word=0x24593f0) at ../sysdeps/unix/sysv/linux/futex-internal.h:88
        __ret = -512
        oldtype = 0
        err = <optimized out>
#1  __pthread_cond_wait_common (abstime=0x0, mutex=0x24593a0, cond=0x24593c8) at pthread_cond_wait.c:502
        spin = 0
        buffer = {__routine = 0x7f2fc1ec9e00 <__condvar_cleanup_waiting>, __arg = 0x7f2fc0ad8e60, __canceltype = 0, __prev = 0x0}
        cbuffer = {wseq = 4, cond = 0x24593c8, mutex = 0x24593a0, private = 0}
        err = <optimized out>
        g = 0
        flags = <optimized out>
        signals = 0
        result = 0
        seq = 2
#2  __pthread_cond_wait (cond=0x24593c8, mutex=0x24593a0) at pthread_cond_wait.c:655
No locals.
#3  0x000000000142e519 in uv_cond_wait (cond=<optimized out>, mutex=<optimized out>) at ../deps/uv/src/unix/thread.c:641
No locals.
#4  0x0000000001238a24 in node::BackgroundRunner(void*) ()
No symbol table info available.
#5  0x00007f2fc1ec37fc in start_thread (arg=0x7f2fc0ad9700) at pthread_create.c:465
        pd = 0x7f2fc0ad9700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139843072792320, -4286327906685610494, 140723879699182, 140723879699183, 139843072792320, 139843072793024, 4241377243362301442, 4241375600262583810}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0,
              canceltype = 0}}}
        not_first_call = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#6  0x00007f2fc1bf0b0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
No locals.

Thread 1 (Thread 0x7f2fc2ff1b80 (LWP 25650)):
#0  0x0000000001051c80 in v8::internal::RegExpResultsCache::Clear(v8::internal::FixedArray*) ()
No symbol table info available.
#1  0x0000000000e576da in v8::internal::Heap::MarkCompactPrologue() ()
No symbol table info available.
#2  0x0000000000e57d9f in v8::internal::Heap::MarkCompact() ()
No symbol table info available.
#3  0x0000000000e736a9 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) ()
No symbol table info available.
#4  0x0000000000e74578 in v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [clone .constprop.934] ()
No symbol table info available.
#5  0x0000000000e750fc in v8::internal::Heap::ReserveSpace(std::vector<v8::internal::Heap::Chunk, std::allocator<v8::internal::Heap::Chunk> >*, std::vector<unsigned char*, std::allocator<unsigned char*> >*) ()
No symbol table info available.
#6  0x00000000010cd707 in v8::internal::Deserializer::ReserveSpace() ()
No symbol table info available.
#7  0x00000000010dccce in v8::internal::StartupDeserializer::DeserializeInto(v8::internal::Isolate*) ()
No symbol table info available.
#8  0x0000000000f1ab45 in v8::internal::Isolate::Init(v8::internal::StartupDeserializer*) ()
No symbol table info available.
#9  0x00000000010dc391 in v8::internal::Snapshot::Initialize(v8::internal::Isolate*) ()
No symbol table info available.
#10 0x0000000000af1ac8 in v8::IsolateNewImpl(v8::internal::Isolate*, v8::Isolate::CreateParams const&) ()
No symbol table info available.
#11 0x00000000011f053d in node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) ()
No symbol table info available.
#12 0x00000000011e9d43 in node::Start(int, char**) ()
No symbol table info available.
#13 0x00007f2fc1afd1c1 in __libc_start_main (main=0x8934b0 <main>, argc=1, argv=0x7ffcd4dc65c8, init=<optimized out>, fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7ffcd4dc65b8) at ../csu/libc-start.c:308
        result = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, -4286329670719695358, 9000520, 140723879699904, 0, 0, 4285824592050198018, 4241375059989173762}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x1, 0x8934b0 <main>}, data = {prev = 0x0, cleanup = 0x0, canceltype = 1}}}
        not_first_call = <optimized out>
#14 0x0000000000895671 in _start ()
No symbol table info available.

disassemble:

Dump of assembler code for function _ZN2v88internal18RegExpResultsCache5ClearEPNS0_10FixedArrayE:
   0x0000000001051c70 <+0>:     push   %rbp
   0x0000000001051c71 <+1>:     xor    %eax,%eax
   0x0000000001051c73 <+3>:     mov    %rsp,%rbp
   0x0000000001051c76 <+6>:     nopw   %cs:0x0(%rax,%rax,1)
=> 0x0000000001051c80 <+16>:    movq   $0x0,0xf(%rdi,%rax,1)
   0x0000000001051c89 <+25>:    add    $0x8,%rax
   0x0000000001051c8d <+29>:    cmp    $0x800,%rax
   0x0000000001051c93 <+35>:    jne    0x1051c80 <_ZN2v88internal18RegExpResultsCache5ClearEPNS0_10FixedArrayE+16>
   0x0000000001051c95 <+37>:    pop    %rbp
   0x0000000001051c96 <+38>:    retq
End of assembler dump.

info registers:

rax            0x0      0
rbx            0x245a7c0        38119360
rcx            0x18     24
rdx            0x16b76b0        23819952
rsi            0x163726f        23294575
rdi            0x0      0
rbp            0x7ffcd4dc4bf0   0x7ffcd4dc4bf0
rsp            0x7ffcd4dc4bf0   0x7ffcd4dc4bf0
r8             0x24a84e0        38438112
r9             0x0      0
r10            0x7ffcd4dc4b80   140723879693184
r11            0x1      1
r12            0x218a174        35168628
r13            0x0      0
r14            0x245a7c0        38119360
r15            0x249b6a0        38385312
rip            0x1051c80        0x1051c80 <v8::internal::RegExpResultsCache::Clear(v8::internal::FixedArray*)+16>
eflags         0x10246  [ PF ZF IF RF ]
cs             0x33     51
ss             0x2b     43
ds             0x0      0
es             0x0      0
fs             0x0      0
gs             0x0      0

coredump.node_v9.1.0.zip

@mscdex mscdex added the v8 engine Issues and PRs related to the V8 dependency. label Nov 9, 2017
@mscdex
Copy link
Contributor

mscdex commented Nov 9, 2017

/cc @nodejs/v8

@hashseed
Copy link
Member

hashseed commented Nov 9, 2017

Looking at the backtrace, this seems to be what's happening:

  • V8 creates a new Isolate.
  • We deserialize the heap content from snapshot.
  • For this, we allocate the necessary memory upfront.
  • Somehow this fails, so we trigger a GC so that we can retry. This mechanism is not designed for deserializing the heap though, but for later when we deserialize contexts.
  • Since we have not initialized the heap yet, performing GC fails somewhere.

Did you change the memory restrictions from default? That's the only way that comes to mind that could cause allocation failure at initialization.

@hashseed
Copy link
Member

hashseed commented Nov 9, 2017

FWIW I run into exact the same stack trace when I run d8 --max-old-space-size=1 with ToT V8.

@IIIMADDINIII
Copy link
Author

I haven't set memory restrictions intentionaly, but i don't now if udev does some type of restriction.

@bnoordhuis
Copy link
Member

@IIIMADDINIII I'm closing this out for now for lack of activity. If you have anything to report, let me know and I'll reopen.

@IIIMADDINIII
Copy link
Author

After I noticed that a sh script couldn't write a file I have installed Ubuntu 16.04 LTS. Now it is working. So it is no Bug in Node. Thanks for the quick help!!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
v8 engine Issues and PRs related to the V8 dependency.
Projects
None yet
Development

No branches or pull requests

4 participants