Learning how to analyze .net core dumps on Linux with lldb and SOS plugin was really rewarding experience. It just feels good knowing that I can see managed stacks, objects and threads in something that looks very native and unmanaged. I saw there are also lldb plugins for Python and Java, but… can I do the same for NodeJS and JavaScript? Well, of course!
There’s llnode
plugin which does exactly that. Today I’m not going to go deeply into how it works – it’s not in the focus of my daily job now. But it’s still interesting to get a feeling of it. So, let’s dive right in.
Getting the tools installed
Today for a change (and for lack of better hardware), I’m going to experiment directly on MacOS, so there won’t be any Docker or apt-get
‘s. I already have NodeJS v8.9.4, so the only remaining components to get are llnode
and lldb
themselves. If MacOS wasn’t on its way of becoming Windows, the following two lines would do:
- brew update && brew install --with-lldb --with-toolchain llvm – get lldb,
- sudo npm install -g llnode – get llnode.
However, in my case everything that could go wrong did went wrong. “Please install XCode”, “Please configure code signing certificate”, “Access denied”. Eventually I managed to get all the pieces together except for llnode
command line tool itself. However, as that’s just a shell file that starts lldb
with llnode
plugin enabled and I do have the plugin, we don’t really need that.
So the remaining step is to enable automatic dumps generation and we’re good to go: ulimit -c unlimited
.
Getting a core dump
This JavaScript should fail,
1 2 3 |
setTimeout(function delayedFailure () { throw new Error("Fail not really fast"); }, 500); |
while this shell command will launch it and instruct nodejs to fail with a core dump, if it has to:
1 2 3 4 5 6 7 8 9 |
node --abort-on-uncaught-exception throw.js #Uncaught Error: Fail not really fast # #FROM #Timeout.delayedFailure [as _onTimeout] (/Users/pav/Documents/llnode/throw.js:1:1) #ontimeout (timers.js:1:1) #tryOnTimeout (timers.js:1:1) #Timer.listOnTimeout (timers.js:1:1) #Illegal instruction: 4 (core dumped) |
It takes node
a little while to crush, because even for such simple program it produces 1.7 GB core dump file. Not the largest one I’ve seen, but not the smallest one either.
1 2 3 |
ls -lh /cores #total 3652896 #-r-------- 1 pav admin 1.7G Feb 21 06:42 core.11787 |
Good. The dump is there, it’s time to look inside of it.
Looking inside of nodejs core dump
It actually feels very same as when I was working with .NET Core dumps.
1 2 3 4 5 |
lldb `which node` -c /cores/core.11787 # (lldb) target create "/usr/local/bin/node" --core "/cores/core.11787" # Core file '/cores/core.11787' (x86_64) was loaded # (lldb) plugin load /usr/local/opt/llnode/llnode.dylib # (lldb) |
llnode
plugin adds several new lldb
commands. All of them start with v8
– easy to remember. For instance, just v8
will output the help about whole 8 subcommands that it supports:
- bt
- findjsinstances
- findobjects
- findrefs
- inspect
- nodeinfo
- source
Back trace
bt
is a default command to try even in non-nodejs dumps, so it seems logical to start with it first.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
(lldb) v8 bt * thread #1: tid = 0x0000, 0x0000000100b26fa2 node`v8::base::OS::Abort() + 18, stop reason = signal SIGSTOP * frame #0: 0x0000000100b26fa2 node`v8::base::OS::Abort() + 18 frame #1: 0x000000010064bc13 node`v8::internal::Isolate::Throw(v8::internal::Object*, v8::internal::MessageLocation*) + 835 frame #2: 0x00000001007f6bab node`v8::internal::Runtime_Throw(int, v8::internal::Object**, v8::internal::Isolate*) + 59 frame #3: 0x00003f456918463d <exit> frame #4: 0x00003f456928443a <stub> frame #5: 0x00003f456923f9ce delayedFailure(this=0x00002d7d26e09e91:<Object: Timeout>) at /Users/pav/Documents/llnode/throw.js:1:97 fn=0x00002d7d26e09da9 frame #6: 0x00003f45692744c9 <stub> frame #7: 0x00003f456923f9ce ontimeout(this=0x00002d7d19602311:<undefined>, 0x00002d7d26e09e91:<Object: Timeout>) at timers.js:90:18 fn=0x00002d7d01b23c29 frame #8: 0x00003f4569274ed2 <stub> frame #9: 0x00003f456923f9ce tryOnTimeout(this=0x00002d7d19602311:<undefined>, 0x00002d7d26e09e91:<Object: Timeout>, 0x00002d7d26e0a821:<Object: TimersList>) at timers.js:90:18 fn=0x00002d7d01b23b09 frame #10: 0x00003f4569275002 <stub> #.... |
The command immediately proves itself worthy, as we’ve got the whole faulting call stack with our delayedFailure
JavaScript function (line 8) being right in the middle of it. But we can get more.
Viewing the source
While looking through the faulting call stack, we can request the source code for its individual frames. For instance, delayedFailure
function was in the 5th one:
1 2 3 |
# ... frame #5: 0x00003f456923f9ce delayedFailure(this=0x00002d7d26e09e91:<Object: Timeout>) at /Users/pav/Documents/llnode/throw.js:1:97 fn=0x00002d7d26e09da9 # ... |
We can switch to that frame and view its source:
1 2 3 4 5 6 |
(lldb) frame select 5 #frame #5: 0x00003f456923f9ce #-> 0x3f456923f9ce: movq -0x20(%rbp), %rbx # 0x3f456923f9d2: movl 0x2b(%rbx), %ebx # 0x3f456923f9d5: leave # 0x3f456923f9d6: popq %rcx |
The command for that is called v8 source list
, but it doesn’t look that it always works:
1 2 |
(lldb) v8 source list # error: USAGE: v8 source list |
However, if we pass additionally frame address, it’ll finally do its thing:
1 2 3 4 5 |
(lldb) v8 source list 0x00003f456923f9ce # 1 (function (exports, require, module, __filename, __dirname) { setTimeout(function delayedFailure () { # 2 throw new Error("Fail not really fast"); # 3 }, 500); # 4 |
Examining the memory
We didn’t have any interesting objects in the memory, but we still can check if there’s anything there created by the environment:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
(lldb) v8 findjsobjects # Instances Total Size Name # ---------- ---------- ---- # 1 24 AssertionError # 1 24 AsyncResource # 1 24 FastBuffer #... # 1 24 console #... # 53 3392 NativeModule # 331 10592 (Array) # 624 35048 Object # 6814 77256 (String) # ---------- ---------- # 7910 131976 |
There’s a console
object and we can look for its instances with findjsinstances
:
1 2 |
(lldb) v8 findjsinstances console #0x00002d7dbce9b829:<Object: console> |
Or go even further: inspect
what that console
is made of:
1 2 3 4 5 6 7 8 9 10 |
(lldb) v8 inspect 0x00002d7dbce9b829 # 0x00002d7dbce9b829:<Object: console properties { # .debug=<unknown field type>, # .error=<unknown field type>, # .info=<unknown field type>, # .log=<unknown field type>, # .warn=<unknown field type>, # .dir=<unknown field type>, # .dirxml=<unknown field type>, #... |
Apparently, it’s made of properties. What a reveal. Other than that, there’s not much to see here.
Conclusion
Dealing with .NET Core and NodeJS core dumps actually feels very similar. Respective plugins provide different commands set, but underlying principles are the same: view call stacks and examine memory. .NET Core’s SOS plugin does, however, provide some features that llnode doesn’t. E.g. GC analysis. Given that JavaScript runtime also has Garbage Collection, being able to track GC heaps and object roots might’ve been handy in some scenarios. But for basic troubleshooting it seems good enough.