trap invalid opcode ip:fea6f9

Strange error crushes all node processes on AWS EC2 instance without change to catch it. And, of course, it forces instance to restart. Previously (in node 0.6) I have seen error "invalid opcode 0000", but this one seems different (node 5.0.0).
Full error text is

trap invalid opcode ip:fea6f9 sp:7ffcdc661708 error:0 in node[400000+1306000]

Does it happen right away at startup? Does your application use native add-ons directly or indirectly? If find node_modules -name \*.node finds anything, the answer is yes.

Yesterday, I was getting similar errors intermittently when running the tests from master

trap invalid opcode ip:e2c519 sp:7fff385218d8 error:0 in node[400000+e18000]

It's a Jessie 64bit box.

Yes, I am using some native add-ons, but error appears not on startup, but in work under few hundreds connections.

In fact, it appears a few times in day. I am using weak, bufferutil, kerberos, utf-8-validate, segfault-handler and some other native modules. Maybe it's bad idea to use segfault-handler in release, but I am doing it because of #3715

Can you turn on core dumps with ulimit -c unlimited? Once you have a core dump, try loading it in gdb and checking the stack trace:

$ gdb node core
> thread apply all backtrace full
# post what's printed

The problem is that error happens only in release, which is EC2 autoscaled instance, so I have no time to call "thread apply all backtrace full" before instance will be terminated.

But I'll try it on one instance, hope it'll be useful.

I don't know if it's the same issue or an issue at all, but running test-domain-with-abort-on-uncaught-exception.js causes a trap invalid opcode ip:e2c519 kernel trace in my machine. The process does not crash though. Specifically running:

testDomainExceptionHandling('--abort_on_uncaught_exception', {
    throwInDomainErrHandler: true,
    useTryCatch: false
});

@santigimeno

@santigimeno That's expected. The test starts a child process that is expected to abort. The 'invalid opcode' is the UD2 instruction that the child process uses to terminate itself.

@bnoordhuis

@bnoordhuis I understand. Thanks a lot for the info. I didn't know about it

@bnoordhuis

@bnoordhuis, I got it, it's pretty short...

warning: Can't read pathname for load map: Input/output error.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `next engine worker                                               '.
Program terminated with signal 4, Illegal instruction.
#0  0x0000000000fea6f9 in v8::base::OS::Abort() ()

Did you run thread apply all backtrace full in gdb?

@bnoordhuis

Sorry, @bnoordhuis, my fault. This one:

warning: core file may not match specified executable file.
[New LWP 4375]
[New LWP 4376]
[New LWP 4380]
[New LWP 4379]
[New LWP 4382]
[New LWP 4378]
[New LWP 4383]
[New LWP 4381]
[New LWP 4377]

warning: Can't read pathname for load map: Input/output error.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `next engine worker                                               '.
Program terminated with signal 4, Illegal instruction.
#0  0x0000000000fea6f9 in v8::base::OS::Abort() ()
(gdb) thread apply all backtrace full

Thread 9 (Thread 0x7f585abf3700 (LWP 4377)):
#0  0x00007f585b78d490 in sem_wait () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#1  0x0000000000fe9518 in v8::base::Semaphore::Wait() ()
No symbol table info available.
#2  0x0000000000e878a9 in v8::platform::TaskQueue::GetNext() ()
No symbol table info available.
#3  0x0000000000e879fc in v8::platform::WorkerThread::Run() ()
No symbol table info available.
#4  0x0000000000fea4d0 in v8::base::ThreadEntry(void*) ()
No symbol table info available.
#5  0x00007f585b786b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#6  0x00007f585b4d095d in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#7  0x0000000000000000 in ?? ()
No symbol table info available.

Thread 8 (Thread 0x7f58520dc700 (LWP 4381)):
#0  0x00007f585b78b344 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#1  0x0000000000fdf8e9 in uv_cond_wait (cond=cond@entry=0x192cfc0, mutex=mutex@entry=0x192cf80) at ../deps/uv/src/unix/thread.c:380
No locals.
#2  0x0000000000fd1148 in worker (arg=arg@entry=0x0) at ../deps/uv/src/threadpool.c:75
        w = <optimized out>
        q = <optimized out>
#3  0x0000000000fdf449 in uv__thread_start (arg=<optimized out>) at ../deps/uv/src/unix/thread.c:49
        ctx_p = <optimized out>
        ctx = {entry = 0xfd1100 <worker>, arg = 0x0}
#4  0x00007f585b786b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#5  0x00007f585b4d095d in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#6  0x0000000000000000 in ?? ()
No symbol table info available.

Thread 7 (Thread 0x7f58510da700 (LWP 4383)):
#0  0x00007f585b78b344 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0

Was the output clipped? 9 threads were started but the backtrace only shows 3.

Without more information there is not much we can do.

Can you guide me what shall i run on the box to get more data for you to find issue?

See #3898 (comment). Also, please check if you are using native add-ons (see #3898 (comment)) and disable them if you do.

Hi

We dont use any native add-ons in our code, mostly all NPM public repo only.
A quick question is the core dump enabled by default or we need to enable it before running our node code in the box?

I see the a crash file under /var/crash/_usr_bin_nodejs.110.crash , will try to get the gdp output and paste here

Can you please help us, if i run gdb node _usr_bin_nodejs.110.crash i dont see anything,
can you please guide how can we use this crash file to get the output ?

Here is the OUTPUT

Thread 2 - 9 are waiting #1  0x0000000000fd9598 in v8::base::Semaphore::Wait() ()

Thread 1 is where i see Abort

Thread 1 (Thread 0x7f7ec046b780 (LWP 24093)):
#0  0x0000000000fda799 in v8::base::OS::Abort() ()
No symbol table info available.
#1  0x0000000000af0f94 in v8::internal::PointersUpdatingVisitor::CheckLayoutDesc---Type <return> to continue, or q <return> to quit---
riptorAndDie(v8::internal::Heap*, v8::internal::Object**) ()
No symbol table info available.
#2  0x0000000000af112d in v8::internal::PointersUpdatingVisitor::VisitPointer(v8::internal::Object**) ()
No symbol table info available.
#3  0x0000000000befa23 in v8::internal::ObjectVisitor::VisitCodeEntry(unsigned char*) ()
No symbol table info available.
#4  0x0000000000af4827 in v8::internal::SlotsBuffer::UpdateSlots(v8::internal::Heap*) ()
No symbol table info available.
#5  0x0000000000af817a in v8::internal::MarkCompactCollector::EvacuateNewSpaceAndCandidates() ()
No symbol table info available.
#6  0x0000000000af9a23 in v8::internal::MarkCompactCollector::SweepSpaces() ()
No symbol table info available.
#7  0x0000000000b037a8 in v8::internal::MarkCompactCollector::CollectGarbage()
    ()
No symbol table info available.
#8  0x0000000000aba100 in v8::internal::Heap::MarkCompact() ()
No symbol table info available.
#9  0x0000000000ad1948 in v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) ()
---Type <return> to continue, or q <return> to quit---
No symbol table info available.
#10 0x0000000000ad1ee9 in v8::internal::Heap::CollectGarbage(v8::internal::GarbageCollector, char const*, char const*, v8::GCCallbackFlags) ()
No symbol table info available.
#11 0x0000000000ad21e5 in v8::internal::Heap::CollectAllGarbage(int, char const*, v8::GCCallbackFlags) ()
No symbol table info available.
#12 0x00000000008f7b57 in v8::Isolate::RequestGarbageCollectionForTesting(v8::Isolate::GarbageCollectionType) ()
No symbol table info available.
#13 0x0000000000909312 in v8::internal::FunctionCallbackArguments::Call(void (*)(v8::FunctionCallbackInfo<v8::Value> const&)) ()
No symbol table info available.
#14 0x0000000000933301 in ?? ()
No symbol table info available.
#15 0x000000000093375e in ?? ()
No symbol table info available.
#16 0x00001b9e55a0963b in ?? ()
No symbol table info available.
#17 0x0000000000000002 in ?? ()
No symbol table info available.
#18 0x00001b9e55a09581 in ?? ()
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#19 0x00007fffc7ad0a90 in ?? ()
No symbol table info available.
#20 0x00007fffc7ad0ae8 in ?? ()
No symbol table info available.
#21 0x00001b9e701f36c2 in ?? ()
No symbol table info available.
#22 0x0000230c03712bd1 in ?? ()
No symbol table info available.
#23 0x0000230c03708dc1 in ?? ()
No symbol table info available.
#24 0x0000230c03712bd1 in ?? ()
No symbol table info available.
#25 0x00003247583041b9 in ?? ()
No symbol table info available.
#26 0x000007b62664fc91 in ?? ()
No symbol table info available.
#27 0x00003349e5004859 in ?? ()
No symbol table info available.
#28 0x00007fffc7ad0b18 in ?? ()
No symbol table info available.
#29 0x00001b9e587939f3 in ?? ()
No symbol table info available.
#30 0x000007b62664d0d9 in ?? ()
---Type <return> to continue, or q <return> to quit---
No symbol table info available.
#31 0x000007b62664fc91 in ?? ()
No symbol table info available.
#32 0x000007b62664fc49 in ?? ()
No symbol table info available.
#33 0x000007b626651b71 in ?? ()
No symbol table info available.
#34 0x00007fffc7ad0b90 in ?? ()
No symbol table info available.
#35 0x00001b9e587934c1 in ?? ()
No symbol table info available.
#36 0x000007b62664d0d9 in ?? ()
No symbol table info available.
#37 0x000007b62664fc49 in ?? ()
No symbol table info available.
#38 0x00003ee299d74b89 in ?? ()
No symbol table info available.
#39 0x00003247583041b9 in ?? ()
No symbol table info available.
#40 0x00003247583041b9 in ?? ()
No symbol table info available.
#41 0x0000324758304211 in ?? ()
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#42 0x000007b62664d0d9 in ?? ()
No symbol table info available.
#43 0x0001d4e200000000 in ?? ()
No symbol table info available.
#44 0x52d11f9500000000 in ?? ()
No symbol table info available.
#45 0x000007b62663b0e9 in ?? ()
No symbol table info available.
#46 0x00003349e5004849 in ?? ()
No symbol table info available.
#47 0x00003ee299d75461 in ?? ()
No symbol table info available.
#48 0x00003ee299d74b89 in ?? ()
No symbol table info available.
#49 0x00007fffc7ad0bc8 in ?? ()
No symbol table info available.
#50 0x00001b9e55a318fd in ?? ()
No symbol table info available.
#51 0x000007b62663b0e9 in ?? ()
No symbol table info available.
#52 0x00003ee299d75461 in ?? ()
No symbol table info available.
#53 0x00001b9e55a31801 in ?? ()
---Type <return> to continue, or q <return> to quit---
No symbol table info available.
#54 0x0000000800000000 in ?? ()
No symbol table info available.
#55 0x0000000000000000 in ?? ()
No symbol table info available.

The v8::Isolate::RequestGarbageCollectionForTesting frame in the stack trace suggests that you're running with --expose_gc. What happens when you remove that flag? Also, why are you passing it?

@bnoordhuis

@bnoordhuis I use this flag too, it provokes the same error as for @rupamkhaitan. But without it I have slow memory leak (even when there is no requests to server). Is this flag will be deprecated or it's just bad practice?

--expose_gc is really just for testing, I wouldn't recommend it for production use.

without it I have slow memory leak (even when there is no requests to server)

That suggests the server is still doing something. Have you tried taking heap snapshots and comparing them over time?

I tried, but, I think, I spent not enough time.

We are using PM2 and yes we pass --expose-gc

PM2_OPTIONS = ' --node-args="--expose-gc" --merge-logs --error /dev/null --output /dev/null'

As @Unterdrucker suggested without this memory leaks and garbage collection is slow.
What is the recommendation

Also in our node code we are calling global.gc() after every 5-10mins to improve the memory because we saw earlier that node builtin garbage collector was not waking up on time and our memory was getting choked, due to which we decided to call it with some interval

What is the recommendation

Fix the memory leak. :-)

In all seriousness, what makes you think you have a memory leak? Does the process eventually abort with a fatal out-of-memory error? If not, you are probably focusing on RSS too much; it's not a good indicator of a memory leak in node.js.

Even if it does die with an OOM error, that doesn't necessarily mean --expose_gc is a proper fix, it might just be delaying the inevitable.

In general, if you think you have a memory leak, analyze it with a tool like node-heapdump or node-inspector or (soon - already available in master) the built-in inspector.

@bnoordhuis

@bnoordhuis yes, it falls with 'cannot allocate' error. With forced GC it works months, but without, dies after 3 days uptime. But, thanks for advise, I am going to work on it :)

Navigation Menu

Repository navigation

trap invalid opcode ip:fea6f9 #3898

16 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

trap invalid opcode ip:fea6f9 #3898

Description

Activity

bnoordhuis commented on Nov 18, 2015

santigimeno commented on Nov 18, 2015

Smbc1 commented on Nov 18, 2015

Smbc1 commented on Nov 18, 2015

bnoordhuis commented on Nov 18, 2015

Smbc1 commented on Nov 18, 2015

Smbc1 commented on Nov 18, 2015

santigimeno commented on Nov 18, 2015

bnoordhuis commented on Nov 18, 2015

santigimeno commented on Nov 18, 2015

Smbc1 commented on Nov 20, 2015

bnoordhuis commented on Nov 21, 2015

Smbc1 commented on Nov 21, 2015

bnoordhuis commented on Nov 21, 2015

16 remaining items

bnoordhuis commented on Jun 27, 2016

rupamkhaitan commented on Jun 27, 2016

bnoordhuis commented on Jun 27, 2016

rupamkhaitan commented on Jun 27, 2016

rupamkhaitan commented on Jun 27, 2016

rupamkhaitan commented on Jun 27, 2016

rupamkhaitan commented on Jun 27, 2016

bnoordhuis commented on Jun 27, 2016

Smbc1 commented on Jun 28, 2016

bnoordhuis commented on Jun 28, 2016

Smbc1 commented on Jun 28, 2016

rupamkhaitan commented on Jun 28, 2016

rupamkhaitan commented on Jun 28, 2016

bnoordhuis commented on Jun 28, 2016

Smbc1 commented on Jul 1, 2016

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions