Superagent: remove annoying "double callback" warning

[stephenmathieson]

i'd rather have an error thrown than console.warn('double callback!')

[tj]

it's a bug in superagent, that's why it's a warn, crashing your entire proc is definitely less ideal

[stephenmathieson]

hmm.. ok. workaround?

[gjohnson]

@visionmedia I could just change it to debug() for now.

[stephenmathieson]

+1 for debug :)

[tj]

oh wait actually now i forget, i dont think it was a superagent bug, ignoring it is no good, but throwing is also no good

[nickl-]

@stephenmathieson this warning is implemented to avoid double callbacks and you should not be getting the warning.

Without any clue as to how your implementation is triggering this warning I will not attempt to thumb suck a cause. Can you try and isolate and produce an example (in the least amount of code) which causes this warning to appear?

Another related issue #290 which may provide additional clues but please don't refrain from providing the example snippet for future reference and aiding others.

[stephenmathieson]

@visionmedia superagent is ignoring it. it's just returning and writing stuff to stderr.

@nickl- yeah, as it's an implementation issue, it sounds like throwing is exactly what should happen..

[gjohnson]

@stephenmathieson can you please add a snippet/gist of the code you have that causes it?

[tj]

it should pass the error but at the time when we had this we couldn't afford crashing node processes over and over so I added a warning

[stephenmathieson]

@gjohnson i don't have it anymore. i had not committed, as it was broken :p if i come across it again, i'll post it

[nickl-]

In absence of the much needed cause of the problem as silver lining at least we can celebrate @stephenmathieson's issue resolved \o/

Advise mark "Works as intended" and close.

[jonasfj]

I might be doing something wrong, but I had the double callbacks warning with this:

        var req = request
                    .put(someUrl)
                    .set('Content-Type', contentType);
        var stream = fs.createReadStream(file);
        stream.pipe(req);
        req.end(function(res) {....});

[nickl-]

Tx @jonasfj this will definitely help to narrow it down. You rock!

[tj]

@jonasfj in that snippet you're piping to req which should already call .end(), you'll get an end event (or should at least)

[jonasfj]

Yeah, it was probably just me doing it wrong... I got it working by using stream.pipe(req, {end: false}). But I guess the alternative is to listen for an end event, perhaps end I tried a couple of different events like response, etc. The type of event seemed undocumented, so...

Anyways, this is more likely a case of me being confused by the documentation.

[tj]

no worries, streams are like that they don't really make sense in their current state

[nickl-]

From the code it is obvious that the double callback was prevented, the warning however raises alarm that this is a problem but we already circumvented the problem when the warning was raised.

The questions that remain:

• is this a problem or does the raised exception sufficiently solve the problem?
• is double callback the only problem and no other concerns remain?
• do we have to raise exception or would simply avoid on condition with an if and return suffice?
• do we have to raise a warning or would console.info or console.log suffice?
• if message is desired can we come up with better wording to address these questions?

[MattCain]

I'm getting the double callback message when testing (with mocha) the GET routes of my API:

it('should get the account metadata', function(done) {
    request.get('https://***/api/user/1')
    .end(function(e, res) {
        expect(res.body).to.have.property('_id');
        expect(res.body).to.have.property('created');
        done();
    });
});

None of my POST/PUT/DELETE requests are getting it and they're in the same format. What's causing it in this case?

[joerx]

Why am I getting this for something as simple as piping a stream? It's basically done like in the docs, so going by the docs is causing warning? Or am I missing something?

var s = http.createServer(app);
s.listen(0);
var addr = s.address();
var host = addr.address;
var port = addr.port;

var req = agent.put('http://' + host + ':' + port + '/documents/' + id).type('application/pdf');

var stream = fs.createReadStream(__dirname + '/data/sample.pdf');
stream.pipe(req);

// results in 'double callback'....

[kof]

I am getting it also very often, we need to identify reasons and fix it finally. Probably in some cases it is ok when its double called and there is no need for the warning. Just ensure not calling users callback twice.

[jonasfj]

Try piping the stream with options end as false.
Ie. stream.pipe(req, {end: false});
and then do req.end() manually...

It sounds like a bug that you can just rely on end from stream...

[cedric-b]

Getting the same entering every superagent .end() cb but this happens only when using gulp watch... Manual CLI mocha or gulp "test" (task piping gulp-mocha) work allright. Only in gulp watch mode surveying test/*.js and triggering "test" task.
Code sample (though pretty much like some others samples here):

it('No status is provided. Returns [500: ' + errmsg.noStatus + ']', function(done) {
  agent.put('http://localhost:3000/api/invoice')
    .send(fixt.invoices.no_status)
    .end(function(err, res) {
      // double callback
      should.not.exist(err);
      res.status.should.eql(500);
      res.type.should.eql('text/plain');
      res.text.should.eql(errmsg.noStatus);
      done();
    });
});
---------
// gulpfile part
gulp.task('test', function() {
  gulp.src('test/*.js')
    .pipe(mocha({reporter: 'spec'}));
});
gulp.task('watch-test', function() {
  gulp.watch('test/*.js', ['test']);
});

Nothing new since last comment on July ?

[cesarandreu]

Having same issue, not sure why :(.

[kfng7]

I also got the same issue when the remote server is down. I expect that error message should be passed via callback instead.

[lukebayes]

Also experiencing this issue using gulp watch with mocha.

var request = require('supertest'),
      worker = require('../src/worker');

describe('POST /message', function() {
  var app;

  beforeEach(function() {
    app = worker();   
  });

  it('handles valid request', function(done) {
    request(app)
      .post('/message')
      .send({version: 10, docId: 'blah'})
     .expect(200, function(err, response) {
        assert.equal(resonse.body, 'some content');
     })
     .end(done);
  });
});

This test passes the first time every time. Then after about 3 file saves it will fail for the next few file saves, and eventually pass again intermittently going back and forth with the double callback error.

TypeError: Cannot read property 'length' of undefined
    at Test.Request.callback ([project]/node_modules/supertest/node_modules/superagent/lib/node/index.js:746:14)
    at ClientRequest.<anonymous> ([project]/node_modules/supertest/node_modules/superagent/lib/node/index.js:711:10)
    at ClientRequest.EventEmitter.emit (events.js:95:17)
    at Socket.socketOnEnd [as onend] (http.js:1568:9)
    at Socket.g (events.js:180:16)
    at Socket.EventEmitter.emit (events.js:117:20)
    at _stream_readable.js:919:16
    at process._tickDomainCallback (node.js:463:13)

[lukebayes]

I may have found the root cause and a workaround.

It looks like providing a callback handler to expect _and_ adding an end handler may intermittently trigger this multiple callback warning.

I have changed our test code to always pass a callback to expect, never call end() and the provided handler calls done() directly.

Haven't seen a recurrence for an hour or so.

[JohnTigue]

I found my way here because of "double callback!" messages while running Mocha tests with Nock. I am leaving this message mostly to cross-link to more info at #417.

And in Nock's issues: https://github.com/pgte/nock/issues/211

One small trick for checking to see if the SuperAgent-to-Nock interaction is your problem is to call nock.enableNetConnect() right before firing off a request with SuperAgent. Toggle that on and off with comments while running Mocha and you might just have found where your prey is hiding.

[SGrondin]

I have found a workaround for my particular case.

In a mocha test file, I was doing:

request.post("http://127.0.0.1/")
.send(new Buffer(1024*1025))
.end(function(err, result) {
    // Some asserts go here
    done()
})

I changed it to

var buf = new Buffer(1025*1024).toString("utf8")
request.post("http://127.0.0.1/")
.send(buf)
.end(function(err, result) {
    // Some asserts go here
    done()
})

and the problem disappeared

[asperling]

Same here but with a slightly different environment. I use supertest-as-promised and therefore my tests are promise based.

But my solution might be of interest anyway, since I figured that the _double callback_ issue disappeared when I re-instantiated the agent in the beforeEach() hook.

var expect = require('chai').expect,
    q = require('q'),
    sap = require('supertest-as-promised'),
    app = require('../../server')
    agent,
    request;

// ...

describe('Some Service Tests', function() {
  beforeEach(function() {
    // reinitialize agent to prevent "double callback"s
    request = sap(q.Promise);
    agent = request.agent(app);
    // ...
  }
  // Tests go here... and so on
}

Now... I never saw the _double callback_ error since.

[JMacLulich]

I'm seeing this problem as well, it happens only sporadically but my end handler is being called twice on some fairly simple code.

request
      .post(url)
      .send(postBody)
      .type('application/json')
      .timeout(TIMEOUT)
      .end(function(err, res) {  ... some stuff gets executed twice for some weird reason... };

I'll try the suggestion about using expect instead of end but not sure why that should matter.

[matthiasg]

@ORESoftware i dont quite follow your code there. Your change should not have corrected this issue as i understand it.

@JMacLulich writes that end is called at least twice, that means in your example you either call the if(err) branch once or twice or the else branch once or twice. In all cases you would call done exactly as often as end was called.

So why does that fix anything ?

[rcrichton]

I'm also seeing the 'double callback!' message and my end() callback doesn't seem to be called (the test times out in mocha). For me it was introduced with supertest 1.1.0 and the same code works fine on 1.0.1. I'm also using mocha for testing and this occurs in a few of our test.

Here is a snippet of code. Is there anything we are doing wrong to cause this?

describe "with no credentials", ->
  it "should `throw` 401", (done) ->
    server.start httpPort: 5001, ->
      request("http://localhost:5001")
        .get("/test/mock")
        .expect(401)
        .end (err, res) ->
          if err
            done err
          else
            done()

[vizath]

I'm having this issue also, when making requests with small timeouts (timeouts that are near the response time).
I can reproduce it by executing this snippet.

var request = require('superagent');
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });
request.get('http://google.com').timeout(140).end(function(err, res) { console.log(err); });

You can make the request only once, but you have more chances to see it if you execute it often.

$ node index.js
null
null
null
null
{ [Error: timeout of 140ms exceeded] timeout: 140, code: 'ECONNABORTED', response: undefined }
{ [Error: timeout of 140ms exceeded] timeout: 140, code: 'ECONNABORTED', response: undefined }
{ [Error: timeout of 140ms exceeded] timeout: 140, code: 'ECONNABORTED', response: undefined }
double callback!
double callback!
double callback!

[alexaivars]

Why is this issue closed ? Im still having problems with double callback, the following simple situation causes a double callback. It might be related to JSON.parse throwing an error further down the chain.

        require('nock')('http://foo.io')
            .get('/invalid')
            .reply(200, 'not valid json', {'Content-Type': 'application/json'})

        require('superagent')
            .get('http://foo.io/invalid')
            .end(function (err, res) {  

            });

[psypersky]

Same problem here

[tribou]

I was seeing the 'double callback!' message along with a fn is not a function error when mocking superagent with sinon. After visionmedia/superagent@454eeb2, the error and double callback message are gone. Did that commit resolve the issue for anyone else?

[matthiasg]

I had this issue again today after doing some extensive unrelated updates in my codebase. In my case the culprit turned out to be the 'faux promise support'.

basically i did something like this (abbreviated):

function send(something,callback){
  return request.post('http://foo.io/invalid').send(something).end(callback);
 }

function main(){
   send(something, function(){ console.log(done) }).then(function(){})
}

the then was added because i used promises in my main code base and the call to send was inside a promise then handler.

Promise.all([...]).then( ()=>send(somedata, function(){...}) )

this happens in ES6 with the above syntax or with e.g coffeescript or with ES5 when its function(){return send(...)}

the return value of my send function is interpreted as a promise thus the faux promise support of Request is called causing end to be called twice.

in the 2nd call this._headerSent is already set to true which means the data is not serialized in the second call causing the req.end(data); to complain about having the wrong format when the send call is given an object.

TL;DR: had the request hooked up with 'end callback' AND '.then callback' causing double request.

[ybian]

I had the same issue. The first case of the following works well but the second prints "double callback" message and the done() callback was not called so timeout error occurred.

It seems that supertest inside a promise then block can easily reproduce the problem.

  it '# success', (done) ->
    supertest(dbServerUrl)
      .get('/_all_dbs')
      .expect(200)
      .end (err) ->
        if err
          done.fail(err)
        else
          done()

  it '# failed', (done) ->
    Q('5')
    .then ->
      supertest(dbServerUrl)
        .get('/_all_dbs')
        .expect(200)
        .end (err) ->
          if err
            done.fail(err)
          else
            done()

[gstamp]

@ybian I also get the same issue when I use promises although in my case I was using bluebird.

[kornelski]

Superagent 2.0 fixes handling of .then()

[vizath]

As of 1.8.3 and 2.0.0-alpha1, my test case higher still outputs double callback!.

[hustcer]

I got the double callback! warning too.

[cdutson]

I'm on 2.0.0-alpha3, and I'm getting double callback

example code:

export const performRequest = function performRequest(url, method='GET') {
 return request(method, url);
};

export const getResource = function getResource(resource, id = null) {
    return performRequest(`${baseUrl}/${resource}/${id}`);
};

export const _doFetch = function _doFetch(id, resolve, reject) {
  // Right here it's double callbacking the .end() causes it.
  // I can even run getResource('sample', id).end() to generate the warning, no resolve/reject needed
  return getResource('sample', id).end((err, res) => { 
    if (res && res.ok) {
     resolve(res.body);
    }
    else {
      reject(err.response);
    }
  });
};

further info: I'm using es6 (not everywhere mind you) that's translated via babel.

[kornelski]

I can't reproduce this issue with any of the code posted in the thread.

I suspect the double callback issue depends on specific HTTP headers and possibly timing of server response, so if you're reporting the issue, please include real, working public URLs that I can investigate.

[cdutson]

@pornel further information that may prove helpful, I only see these warnings when running the code through mocha. so some additional code:

/* import nock, expect, etc */

describe('api code', () => {
   it('Should return values for api call', () => {
    nock('http://33.0.0.16:8000')
      .get('/foo')
      .reply(200, [
        {
          foo: 'bar'
        }
      ]);

    const expectedResults = [
        {
            foo: 'bar'
        }
    ]

    return _doFetch().then((results) => {
      expect(results).toEqual(expectedResults);
    },
    () => { /* swallow error */ });
  });
}

running the code posted above within the test suite causes ... 3 warnings to show up.

cli> node_modules/mocha/bin/_mocha --compilers js:babel-register --recursive --grep "api code"

double callback!
double callback!
double callback!
    ✓ Should return values for api call

the local api server I'm running is a vanilla django rest framework setup. no custom headers or anything.

[romaleev]

Same issue with 'double callback!' with version 1.8.4.
I use PM2 with node.js.
When superagent's timeout exceeded I log the error and run process.exit after which PM2 successfully restarts the node.
However sometimes superagent sends 'double callback!' warning right after I call process.exit which makes my node hang up forever and not being restarted by PM2.
After some investigation I figured out that request callback executes twice:
1) superagent.callback with error -> which resolves it as expected
2) calling process.exit (but it is still running afterwards)
3) then callback executes the second time !!! with a result and no error (result is with content as if request succeeded)
4) superagent returns 'double callback!' warning within neither callback fn execution nor error.
5) node.js is still running

As a conclusion for some reason superagent executes callback twice with no resolving the second one which leads the process to hang up.

[kornelski]

We know 1.8 is buggy — we've already fixed those bugs in later versions. Especially 2.2 and later removed many double callback problems. Please upgrade.

[djabraham]

I was getting double callback because I had the port forwarded via nat using virtual box (boot2docker). I was running a containerized app locally and forgot the same port was used for both.

Funny thing is the server starts and I am able to browse to it with no warnings. But when I run supertest, I encounter the double callback error. Once I changed the port, it worked fine.

I don't consider this a problem, just posting it here for future reference. This was occurring under the latest versions (2.0.0 SA & 2.3.0 ST).

[kornelski]

Superagent 2.0.0 has this bug. The fix is in Superagent 2.2 or later.

Supertest changes quite a lot about behavior of superagent, so if you have a bug that happens when running supertest, please report it to the supertest project.

[vizath]

I can still reproduce https://github.com/visionmedia/superagent/issues/313#issuecomment-141326537 in 3.3 using .timeout(180).
The warning is now superagent: double callback bug.

Note that .timeout({ response:60 }) (introduced in 3.2) works fine with no warnings, but it is not the behavior that I'm looking for (I don't want to wait more than 180ms total including downloading the body).

Could that mean that the warning is shown when there is an error between the moment the connection is established and the body is completely received ?

[kornelski]

Sorry, I can't reproduce this (superagent 3.3, Node 7.2 osx). Timeout is in our test suite.

[kornelski]

If you run into this problem, please change:

  if (this.called) return console.warn('superagent: double callback bug');
  this.called = true;

to

  if (this.called) return console.trace('superagent: double callback bug', this.called);
  this.called = Error("previous trace");

and report the stack traces.

[vizath]

$ node superagent.js
null
null
{ [Error: Timeout of 450ms exceeded] timeout: 450, code: 'ECONNABORTED', response: undefined }
{ [Error: Timeout of 450ms exceeded] timeout: 450, code: 'ECONNABORTED', response: undefined }
{ [Error: Timeout of 450ms exceeded] timeout: 450, code: 'ECONNABORTED', response: undefined }
{ [Error: Timeout of 450ms exceeded] timeout: 450, code: 'ECONNABORTED', response: undefined }
{ [Error: Timeout of 450ms exceeded] timeout: 450, code: 'ECONNABORTED', response: undefined }

Trace: superagent: double callback bug [Error: previous trace]
    at Request.callback ([...]\node_modules\superagent\lib\node\index.js:637:35)
    at Stream.<anonymous> ([...]\node_modules\superagent\lib\node\index.js:849:18)
    at emitNone (events.js:67:13)
    at Stream.emit (events.js:166:7)
    at Unzip.<anonymous> ([...]\node_modules\superagent\lib\node\unzip.js:63:12)
    at emitNone (events.js:72:20)
    at Unzip.emit (events.js:166:7)
    at endReadableNT (_stream_readable.js:905:12)
    at nextTickCallbackWith2Args (node.js:441:9)
    at process._tickCallback (node.js:355:17)

The previous trace:

Error: previous trace
    at Error (native)
    at Request.callback ([...]\node_modules\superagent\lib\node\index.js:642:17)
    at RequestBase._timeoutError ([...]\node_modules\superagent\lib\request-base.js:516:8)
    at null.<anonymous> ([...]\node_modules\superagent\lib\request-base.js:525:12)
    at Timer.listOnTimeout (timers.js:92:15)

You need to play with the timeout values until you get the sweet spot where half of them are timeouts and half of them are success.
Also, having the timeout error doesn't always trigger the trace.

Using a mobile network makes it very hard to reproduce.

[vizath]

I cannot reproduce my use case on 3.3.1 :tada: