"Recursive process.nextTick detected" from within stream code

[kessler]

Hi,

Occasionally (but not rarely) I'm getting the "Recursive process.nextTick detected" warning in huge spams. When using "--throw-deprecation" I get this stack trace:

node.js:375
        throw new Error(msg);
              ^
Error: (node) warning: Recursive process.nextTick detected. This will break in the next version of node. Please use setImmediate for recursive deferral.
    at maxTickWarn (node.js:375:15)
    at process._nextDomainTick (node.js:498:9)
    at emitReadable (_stream_readable.js:400:13)
    at readableAddChunk (_stream_readable.js:165:9)
    at EncryptedStream.Readable.push (_stream_readable.js:127:10)
    at EncryptedStream.read [as _read] (tls.js:510:10)
    at EncryptedStream.Readable.read (_stream_readable.js:320:10)
    at flow (_stream_readable.js:579:52)
    at Socket.<anonymous> (_stream_readable.js:563:7)
    at Socket.EventEmitter.emit (events.js:117:20)

I chose to post this issue since the stack trace is purely node core code.

Even worse, I cannot reliably reproduce it yet (but I'm working VERY hard on that) except by running my production servers under medium - heavy load for arbitrary periods of time.

Servers are amazon machines running the aws linux distro with node v0.10.15.

Any and all help (even sympathy) will be tremendously appreciated.

Thanks!

[bnoordhuis]

@isaacs Looks like a streams issue to me. Handing this off to you.

[kessler]

I just tested on v0.11.0 and the problem persists.

[kessler]

Problem seem to vanish at 0.11.1 - that is, since upgrading its been several hours and no recursion errors. I'll post back in a day.

[kessler]

so far so good, since upgrading to 0.11.1 this problem seemed to go away

[bnoordhuis]

Okay, thanks for reporting back. I'll close the issue.

[kessler]

Hi @bnoordhuis

This bug has resurfaces in one of my college's projects and this time we've distilled it to a fairly simple program (although that simple program is dependent on aws node.js sdk) that reproduces it consistently on several independent machines.

See here:
aws/aws-sdk-js#173

Could someone take a look?

p.s. If you need aws/s3 credentials for testing I can send them privately.

[bnoordhuis]

@kessler We can only accept bug reports with test cases that have no third-party dependencies, i.e. that only use core libraries.

[kessler]

@bnoordhuis this problem is very elusive but clearly its a problem in node core, I've spent several days last time to try and distill a program that reproduces it but it would only occur in high traffic production environment so I was unsuccessful.

If you could tell me how to find the connection between the above asynchronous stack trace and a simple s3.putObject() call (which basically reproduces the problem when the file is large enough) I will gladly try and distill a pure core code. ("point me in the right direction and ill go from there")

I also like to point out that the developers of aws closed our bug report on the grounds that the problem is in node core, developers of node postgres driver did the same so I feel this problem kind of falls between the lines (not sure if that is how you phrase this in english).

A stroke of luck has presented us with a simple program that reproduces this problem repeatedly, so can't there be an exception in this case?

[bnoordhuis]

If one of the other committers wants to pick this up, I'll cheer him on (from the sidelines). From previous experience, in 19 out of 20 cases the bug turns out to be either in the test case or a dependency - meaning you just spent 30 minutes debugging someone else's broken code. No offense but life is too short for that.

That's not to say there are no bugs in node core but I'd rather spend my time fixing those rather than bugs in $RANDOM_LIBRARY.

[kessler]

This occurs across various modules, the two above are just an example.

Could you at least reopen this for a little while so people will take notice, maybe someone could contribute a vital piece of information.

I will keep digging into this myself as well.

[trevnorris]

@kessler the stack trace you posted is too short to see where the emitted event is coming from. If you increase Error.stackTraceLimit = 20 or more and can reproduce w/ the longer stack trace I'll take a look. I'm going to leave it closed until then, but ping me back if you manage to reproduce.

[kessler]

@trevnorris hey, wonderful tip that :) anyways, stack trace didn't come out that much longer:

node.js:375
        throw new Error(msg);
              ^
Error: (node) warning: Recursive process.nextTick detected. This will break in the next version of node. Please use setImmediate for recursive deferral.
    at maxTickWarn (node.js:375:15)
    at process.nextTick (node.js:480:9)
    at emitReadable (_stream_readable.js:400:13)
    at readableAddChunk (_stream_readable.js:165:9)
    at EncryptedStream.Readable.push (_stream_readable.js:127:10)
    at EncryptedStream.read [as _read] (tls.js:514:12)
    at EncryptedStream.Readable.read (_stream_readable.js:320:10)
    at flow (_stream_readable.js:589:52)
    at Socket.<anonymous> (_stream_readable.js:573:7)
    at Socket.EventEmitter.emit (events.js:117:20)
    at onwriteDrain (_stream_writable.js:283:12)
    at afterWrite (_stream_writable.js:271:5)
    at _stream_writable.js:261:9
    at process._tickCallback (node.js:415:13)

Does that get us anywhere yet?

[trevnorris]

@kessler and I'll assume you're using v0.10.20?

[trevnorris]

I have a sorta test case:

var Readable = require('stream').Readable;
var util = require('util');
var b = new Buffer(1);

function MyThing() {
  Readable.call(this);
}
util.inherits(MyThing, Readable);

MyThing.prototype._read = function read(size) {
  this.push(b);
  if (this._readableState.buffer.length > 1000) {
    throw new Error('buffer is huge!');
  }
};

var thing = new MyThing();

setTimeout(function() {
  thing.on('readable', function() {
    thing.read();
  });
}, 10);

@isaacs Could it be possible that if tls is reading in a very large file that it just continues to loop and call nextTick()? That would trigger the error.