[CRASH] Assertion failed: cb->IsFunction() in async-wrap-inl.h at line 230

[branneman]

Exact error

Assertion failed: cb->IsFunction(), file g:\jenkins\workspace\nodejs-msi\d73b0901\src\async-wrap-inl.h, line 230

And that's here: src/async-wrap-inl.h#L230

My system

• Windows 8 Enterprise, 64bit, winver: Version 6.2 (Build 9200)
• Node.js v0.11.12
• 12Gb RAM, 7Gb free at time of running node

My application

• Running Node.js with --harmony flag
• Only dependency is recluster, version 0.3.6
• Constisting of 2 files:
  1. cluster.js: a straightforward recluster configuration
  2. node.js: an example webserver, copy-pasted from nodejs.org, tweaked a tiny bit

To reproduce

File 'cluster.js':

const pkg       = require('./package');
const path      = require('path');
const numCPUs   = require('os').cpus().length;
const recluster = require('recluster');

var app = path.join(__dirname, pkg.main);
var options = {
    workers: numCPUs,
    readyWhen: 'ready'
};
var cluster = recluster(app, options);
cluster.run();

console.log('Cluster started with', numCPUs, 'nodes.');

File 'node.js':

const http = require('http');

const WORKER_ID = parseInt(process.env.WORKER_ID, 10) || 0;

var server = http.createServer(function(req, res) {
    res.end('Hello World from worker ' + WORKER_ID);
}).listen(3000 + WORKER_ID, '127.0.0.1');

server.on('listening', function() {
    // Signal recluster that this node is ready.
    if (process.send) {
        process.send({cmd: 'ready'});
    }
});

Run:

1. node --harmony cluster
2. Wait 5 minutes (it never crashes right after starting the cluster)
3. Request http://localhost:3000/, which will time out
4. Look at your terminal window, it crashed with the error above:
   Assertion failed: cb->IsFunction(), file g:\jenkins\workspace\nodejs-msi\d73b0901\src\async-wrap-inl.h, line 230

The bad news? It doesn't always crash. I hope you guys can reproduce. If further environment info is needed, or I should run some other tests, let me know.

[trevnorris]

Self assigned.

@branneman any chance you could produce a backtrace with this error?

[branneman]

@trevnorris I'd love to, but how to I produce one if I'm not getting one? It's not a Node.js error from JS code, more like a C/C++ crash, so that one message is all I get.

Could you explain how I can make it generate a stack trace?

[indutny]

@branneman does it reproduce for you without external dependencies? What if you would replace recluster with just a cluster?

[branneman]

I was able to reproduce the error with the following source.

But, since the chance that the error occurs is very small, I used JMeter to bombard this little localhost:3000 server, it crashed after about 2k requests.

const cluster = require('cluster');
const numCPUs = require('os').cpus().length;
const http    = require('http');

if (cluster.isMaster) {

    var forks = {};
    for (var i = 0; i < numCPUs; i++) {
        forks[i] = cluster.fork();
        forks[i].on('message', function(msg) {
            console.log('Message from worker', msg.worker + ':', msg.msg, 'on', +new Date);
        });
    }

    console.log('Cluster started with', numCPUs, 'nodes.');
}

if (cluster.isWorker) {

    http.createServer(function(req, res) {
        process.send({
            worker: cluster.worker.id,
            msg: 'request'
        });
        res.end('Hello World from worker ' + cluster.worker.id);
    }).listen(3000, '127.0.0.1', function() {
        console.log('Worker', cluster.worker.id, 'started.');
    });
}

[trevnorris]

@branneman Thanks for the reduced test case. I'll work on reproducing the issue. Hopefully I can on my Linux box because I have no idea how to debug this crap from Windows.

[migounette]

Need help on Windows ? I can have a look if needed.

[migounette]

c:\temp>node test.js
Cluster started with 8 nodes.
Worker 3 started.
Worker 2 started.
Worker 4 started.
Worker 5 started.
Worker 1 started.
Worker 7 started.
Worker 6 started.
Worker 8 started.
Message from worker 8: request on 1401832608368
Message from worker 8: request on 1401832608388
Message from worker 8: request on 1401832608400
Message from worker 8: request on 1401832609300
Message from worker 8: request on 1401832609316
Message from worker 8: request on 1401832609317
Message from worker 8: request on 1401832609319
Assertion failed: cb->IsFunction(), file g:\jenkins\workspace\nodejs-msi\d73b0901\src\async-wrap-inl.h, line 230

With siege on my linux box, I can reproduce.
/usr/local/bin/siege -c100 -t1M http://x.y.z.z:3000

Switching to debug mode.

    node.exe!_NMSG_WRITE(int rterrnum) Line 226 C
    node.exe!abort() Line 72    C
    node.exe!_wassert(const wchar_t * expr, const wchar_t * filename, unsigned int lineno) Line 156 C
>   node.exe!node::AsyncWrap::MakeCallback(const v8::Handle<v8::String> symbol, int argc, v8::Handle<v8::Value> * argv) Line 230    C++
    node.exe!node::TCPWrap::OnConnection(uv_stream_s * handle, int status) Line 341 C++
    node.exe!uv_process_tcp_accept_req(uv_loop_s * loop, uv_tcp_s * handle, uv_req_s * raw_req) Line 1061   C
    node.exe!uv_process_reqs(uv_loop_s * loop) Line 160 C
    node.exe!uv_run(uv_loop_s * loop, uv_run_mode mode) Line 346    C
    node.exe!node::Start(int argc, char * * argv) Line 3605 C++
    node.exe!wmain(int argc, wchar_t * * wargv) Line 61 C++
    [External Code] 

I will investigate more tomorrow:

inline v8::Handle<v8::Value> AsyncWrap::MakeCallback(
    const v8::Handle<v8::String> symbol,
    int argc,
    v8::Handle<v8::Value>* argv) {
  v8::Local<v8::Value> cb_v = object()->Get(symbol);
  v8::Local<v8::Function> cb = cb_v.As<v8::Function>();
  assert(cb->IsFunction()); <== ## !!!! cb is not a function !!!!

  return MakeCallback(cb, argc, argv);
}

[trevnorris]

First, this issue doesn't seem to have anything directly related to the --harmony flag. Second issue is that I can't seems to reproduce on Linux.

Honestly this shouldn't be possible because the the onconnection property has to be set: https://github.com/joyent/node/blob/57c5655/lib/net.js#L1142

@orangemocha The only commit I can find that introduces win32 specific code is 3da36fe. Have any opinions on why this might be happening on windows?

[trevnorris]

@migounette Thanks. The debugging information you're providing is very useful.

[orangemocha]

@trevnorris if this only repros on Windows feel free to assign to me. However I won't be able to look into it for another two weeks as I am working on another high-priority task.

[missing1984]

i have encountered the same issue on Windows 2008r2 running on VMware and ec2. it seems related to cluster only. Everything works fine in linux or not in cluster.

#7667

[orangemocha]

I'm investigating...

[orangemocha]

Fixed with 7ca4fa5

[trevnorris]

@orangemocha Thanks. :)

[branneman]

Will there be v0.10.31 or v0.10.32 where this is fixed, or is this going to be in v0.11.x, and thus v0.12?

[orangemocha]

This fix is in v0.12, which presumably will get integrated into v0.11.
v0.10 shouldn't be affected by this issue.

[branneman]

So there's a 0.12 branch where work is done without it having first been in 0.11? Hm, I was under the impression that the latest 0.11 will become 0.12 eventually, that all the work was done in 0.11.

When will 0.12 be there btw? Not looking for exact dates of course, but will it be this year? Any big features still need to be done, or just bug fixing and building a release?

[orangemocha]

We forked the 0.12 branch last week. Fixes going into 0.12 will be integrated into master (whose version number is currently 0.11).

We are one PR away from being feature-complete for 0.12. After that it's all bug fixes. So yes, it should definitely happen this year.

[branneman]

Awesome!