request.set triggers request in node

[yepitschunked]

> r = require('superagent').get('/')
> r.set({foo: 'bar'})
(seconds later)
> TypeError: fn is not a function
    at Request.callback (...node_modules/superagent/lib/node/index.js:781:12)
    at ClientRequest.<anonymous> (...node_modules/superagent/lib/node/index.js:736:10)
    at emitOne (events.js:77:13)
    at ClientRequest.emit (events.js:166:7)
    at Socket.socketErrorListener (_http_client.js:258:9)
    at emitOne (events.js:77:13)
    at Socket.emit (events.js:166:7)
    at net.js:430:14
    at doNTCallback0 (node.js:415:9)
    at process._tickDomainCallback (node.js:385:13)
> double callback!

I haven't called .end() yet, so no callback is present to handle that error. But the request shouldn't be sent in the first place...

[defunctzombie]

I took a quick look at the code and can't find any place where we would be triggering the request to fire just for setting headers. But I can reproduce the exact behavior you are seeing.

[harry1989]

I took a quick look at the code and realized that, this is happening due to the typo at https://github.com/harry1989/superagent/blob/master/lib/node/index.js#L708. It should be

if (0 != url.indexOf('http')) url = 'http://' + url.

can't find any place where we would be triggering the request to fire just for setting headers.

Contrary to belief we are actually triggering a http request even for setting the headers.

https://github.com/harry1989/superagent/blob/master/lib/node/index.js#L274, this is the cause of the error. I even verified this by monitoring the traffic while set() method is called using tcpdump. Clearly it is triggering the http call.

[yepitschunked]

The (awful) node docs suggest that the request is considered in-flight already as soon as you create it:

This object is created internally and returned from http.request(). It represents an in-progress request whose header has already been queued. The header is still mutable using the setHeader(name, value), getHeader(name), removeHeader(name) API. The actual header will be sent along with the first data chunk or when closing the connection.

So maybe touching the header is making node attempt to send things? That's terrible. :(

[defunctzombie]

I looked into this some more and it has to do with how superagent is behaving and using the built-in node request instances. When you call methods like set, get, unset, superagent calls the .request() method on itself (your superagent request instance). This initializes the node request object and prepares the request (via the node api). Due to the nodejs api behavior, you can still call setHeader on this request object if you are in the same tick (no IO work has been done) since the request will actually go out on the next tick it seems.

This is a tricky one to make a call on since the easy thing to do is to say that superagent should cache headers internally and not do anything until you 'end' your request. That might work for headers, but this same problem seems to plague the .send() call as well (and possibly others).

I am going to say that I think superagent calls need to happen in the same tick and thus you can't pre-create a request with the intention of ending it later. Creating a request means you will be sending if off in that same tick (or at least the headers).

[samyhrer]

This errors occurs in my application alot. I've had no success in reproducing the error as is seem to trigger randomly. Are we guaranteed that a
request.get(..)
.set(..)
.end(..)
operation will happen within the same tick?

[mpjura]

@defunctzombie I'm confused as to why this issue was closed. As @samyhrer noted above even if you initialize the request in the same statement chain, results are spotty.

Running mocha tests with superagent-mocker on this code fails around 20% of the time:

var Service = {
    request = require( "superagent" ),

    edit: function( id, params, callback ) {
        this.request.put( this.formUrl( id ) )
            .set( { "Content-Type" : "application/json" } )
            .send( params )
            .end( callback );
    }
};

[defunctzombie]

@mpjura it was closed because of my explanation above. I have not run into this error myself because I always initiate the request when it is created. I think the superagent API misleads the user into thinking they can create the request and then send it later but that is not really the case. Creating the request will send it off at the end of that tick.

[mpjura]

@defunctzombie maybe I'm confused about when the request gets "created" then. I'm getting errors using the same patterns in the superagent docs. Opened a new issue with all the code to reproduce here: #741

[bminer]

Just to be clear, it appears that this bug is caused when an "error" event is emitted from Node's request Object, which is captured by Superagent; however, since .end(cb) was not yet called on the Superagent request Object, there is no _callback property set yet, and the error is not reported to the user. By the time .end(cb) is called, the error is gone, and cb will never be called (as of Superagent v1.6.1). This bug will only occur if .end(cb) is NOT called in the same tick as the request was created (i.e. you created the request, do some async stuff, then call .end(cb)... and in the meantime an error occurred -- like a connection error or whatever). The end result under these circumstances is that your cb is never called, and the error is not reported to the outside world.

In this case, why not just save any request errors that occur before .end(cb) is called on the Superagent request? Then, when .end(cb) is called, you check if an error has already occurred on the request Object. If so, you call cb, passing the saved error. If not, you continue as normal.

A workaround to this bug is to set _callback on the Superagent request with your desired cb before doing any async work. This is what I decided to do until this bug is corrected.

Thoughts?

[bminer]

I can always submit a PR of my suggestion if you want? I assume this change would be a minor version bump?

[focusaurus]

EDIT: OK, my first analysis was off (I was probably looking at the browser code by mistake). This defunctzombie comment is still an accurate summary of the fundamental problem here.

Thus I don't think near-term avoiding initializing the node request until the very end is probably not feasible, and if we did it, it would probably warrant a semver major and be a big deal.

However, in the case bminer is describing, we should indeed provide a fix to capture the early DNS lookup error and call the callback if .end(cb) is later called.

I'll have to do some more thinking to fix the cases, including DNS lookup failures, timeout expiring before send, etc.

PRs welcome, but I'll try to circle back and make a concrete suggestion after some more focused analysis.

[bminer]

Sorry for the delayed response. Here's some code you can use to replicate the bug:

var request = require("superagent");
function callback(err, res) {
    if(err) {
        console.log("Error:", err.stack);
    } else {
        console.log("Success:", res.status);
    }
}
var req = request.get("http://www.fjkldfjkdjf.com/");
req.set("User-Agent", "Superagent... duh!");
//req._callback = callback; // Workaround: Uncomment this line to "fix" the problem
setTimeout(function() {
    req.end(callback);
}, 1000);

In superagent v1.6.1, callback is never called. EDIT: Actually, it would be called if www.fjkldfjkdjf.com was a valid DNS host, which it currently is not. As mentioned above, the bug only occurs when an "error" event is emitted from the Node HTTP request Object before Superagent's .end(cb) method is called.

If you uncomment the line as noted, callback is called once with the proper Error:

Error: Error: getaddrinfo ENOTFOUND www.fjkldfjkdjf.com www.fjkldfjkdjf.com:80
    at errnoException (dns.js:26:10)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:77:26)

EDIT: However... even though callback is called with the correct Error when setting the _callback property, the callback is called as soon as the Error occurs, NOT when the 1000 ms. timer expires, producing unexpected behavior. Therefore, this workaround is not a perfect solution.

For comparison, in superagent v0.21.0, a message like this occurs:

TypeError: Cannot read property 'length' of undefined
    at Request.callback (/home/blake/Repositories/machine/node_modules/superagent/lib/node/index.js:746:14)
    at ClientRequest.<anonymous> (/home/blake/Repositories/machine/node_modules/superagent/lib/node/index.js:711:10)
    at emitOne (events.js:77:13)
    at ClientRequest.emit (events.js:169:7)
    at Socket.socketErrorListener (_http_client.js:264:9)
    at emitOne (events.js:77:13)
    at Socket.emit (events.js:169:7)
    at connectErrorNT (net.js:998:8)
    at nextTickCallbackWith2Args (node.js:478:9)
    at process._tickDomainCallback (node.js:433:17)

EDIT: For the record, this bug definitely occurs on Node 4.x and 5.x, but it probably also pertains to other versions, as well.

[focusaurus]

OK thanks for posting that snippet. Let me reproduce locally and try to understand what's going on.