process._tickCallback - tock is undefined

[dnwe]

• Version: v4.3.1
• Platform: Linux 4.4.0-1-amd64
• Subsystem: process

node.js:342
          callback = tock.callback;
                         ^

TypeError: Cannot read property 'callback' of undefined
    at process._tickCallback (node.js:342:26)

TL;DR the same issue that someone else previously reported in #4308 (and closed), but with a reduced testcase.

Several of our customers are seeing this after moving from Node 0.12.x to node 4.x.x. The issue appears to be readily reproducible for me on Node 4.x.x (both 4.3.1 and 4.4.3 tested) using the example app here against an mqlight backend, but appears to be "fixed" on Node 5.10.1. Essentially, after some period of the app running, tickInfo[kLength] seems to have got out of sync and is greater-than nextTickQueue.length - hence tock ends up being undefined.

    function _tickCallback() {
      var callback, args, tock;

      do {
        while (tickInfo[kIndex] < tickInfo[kLength]) {
          tock = nextTickQueue[tickInfo[kIndex]++];
          callback = tock.callback;       // <------- line 341. tock is undefined
          args = tock.args;

Further debugging on 4.3.1 /seemed/ to indicate that the issue occurred in nextTick, after pushing the new TickObject nextTickQueue.length was 0 (descoped?), but tickInfo[kLength] was incremented regardless and hence they became out of step.

Applying this patch to src/node.js and re-building seemed to fix the issue for me...but I can't explain why.

[dnwe]

@bnoordhuis - FYI, I thought I'd raise an issue for that bug we chatted about

[bnoordhuis]

I've not been able to reproduce the issue myself so far but I suspect a V8 bug. Do you still see the issue with node --nocrankshaft app.js?

[dnwe]

✅

$ node --nocrankshaft app.js
node.js:340
          callback = tock.callback;
                         ^

TypeError: Cannot read property 'callback' of undefined
    at process._tickCallback (node.js:340:26)

node --nocrankshaft app.js  25.50s user 2.36s system 82% cpu 33.929 total

[bnoordhuis]

@nodejs/v8 Ideas? I remember there was a similar bug a few months back but the details elude me.

[indutny]

@dnwe may I ask you to run it with --trace-ic --nocrankshaft? It will produce tremendous amount of logs, but may help in figuring out the cause of this. Thanks!

[dnwe]

@indutny sure, here you go trace.zip

[dnwe]

@indutny @bnoordhuis : just in case it is useful, here is a xz compressed core file (3.7M) from /opt/node-v4.4.3-linux-x64/bin/node --nocrankshaft --abort-on-uncaught-exception app.js using the linux x64 release from latest-v4.x

% sha256sum /opt/node-v4.4.3-linux-x64/bin/node cf02d6764e1c48ffc0ed95a42a75d46ba1713a702e8ed83bbc3b806ee7eae54e /opt/node-v4.4.3-linux-x64/bin/node

[indutny]

@dnakamura sorry for delay! I'm trying to figure out similar bug at the moment. May I ask you to give it a spin with --no-use-ic flag as well?

[dnwe]

@indutny sure, I'll run that for you tmrw.

We believe the underlying cause /may/ have been related to callbacks we were making to js logger from within destructors in our C++ add-on. After removing those I haven't been able to reproduce again.

[indutny]

@dnwe thank you! That's pretty interesting finding.

However similar thing appears to be happening in node-spdy, which doesn't use any native addons. Either these are two unrelated bugs, or they are a manifestation of the same bug.

[indutny]

Anyway here is a v8 bug: https://bugs.chromium.org/p/v8/issues/detail?id=5009

[hoschid]

I'm the author of #4308. I had the same problem again after i closed that issue. Compiling node with the patch described above by @dnwe solved the problem for me. But I wonder if there's any news on this issue? It seams like the related v8 bug was fixed.

[bnoordhuis]

#7531 should fix this (in v6) when released, assuming v8:5009 is the root cause.

@indutny You want to take a stab at back-porting it to v4.x? It doesn't apply cleanly and I'm not sure if the changes are semantically correct for V8 4.5.