Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Already on GitHub? Sign in to your account

Https.request sporadically fails with "Cannot call method 'emit' of undefined" error #670

Closed
twills opened this Issue Feb 14, 2011 · 44 comments

Comments

Projects
None yet
10 participants

twills commented Feb 14, 2011

This is observed with node 0.4.0 on cygwin. I am calling https.request to connect to a server, and sporadically am experiencing the following exception:

node.js:116
throw e; // process.nextTick error, or 'error' event on first tick
^
TypeError: Cannot call method 'emit' of undefined
at CleartextStream. (http.js:1135:9)
at CleartextStream.emit (events.js:42:17)
at Socket.onerror (tls.js:809:17)
at Socket.emit (events.js:42:17)
at Array. (net.js:799:27)
at EventEmitter._tickCallback (node.js:108:26)

I did some debugging and I believe that what is happening is that the server I am connecting to is sometimes not doing an orderly shutdown of the SSL conversation. This is causing an ECONNABORTED error at my node client. The catch is that the response has already been received and hence some cleanup of the node socket structure has already occurred within node, leaving it with nothing to emit the error event to.

At a code level, take a look at http.js. The crash I am seeing is happening at line 1148, where the code tries to emit the error event on the request object, which is null. It is null because, prior to the error event being emitted on the socket, the listener for the end event on the response (line 1244) was invoked, which cleans up the socket (detachSocket at line 1256). So the code as currently implemented is not expecting that an error event on the socket can be received after the full response has been received.

ry commented Feb 15, 2011

i think you're not listening for the error event.

twills commented Feb 15, 2011

I believe I am. My code basically looks like the following. Should I be doing something differently?

req = https.request(options, fnCB);
req.end();

req.on('error', function(err) {
    console.log(err);
});    

Same happens in my code and I'm also listening to the request error event.

ry commented Feb 18, 2011

please check again on v0.4 HEAD, we've made a lot of changes recently

great seems to work in current v0.4 HEAD!

ry commented Feb 18, 2011

closing. reopen if it persists.

twills commented Feb 18, 2011

I'm no longer seeing the issue with v0.4 HEAD either... Although I didn't have a reproducible test case to begin with, so I can't say with 100% certainty that it is fixed. It's not obvious to me from looking at the source that the recent code changes would have fixed this. Someone who is closer to the code I referenced above might want to take a look and try to deduce whether this issue could still happen with the latest code.

twills commented Mar 16, 2011

This issue is definitely still happening for me on v0.4 HEAD. The current stack trace follows. I wish I had a reproducible test case to provide, but the server I am connecting to is not under my control and I am not exactly sure what is causing this. My theory is still that it is due to the server occasionally not doing a proper shutdown of the SSL connection.

TypeError: Cannot call method 'emit' of undefined
at CleartextStream. (http.js:1167:9)
at CleartextStream.emit (events.js:42:17)
at Socket.onerror (tls.js:830:17)
at Socket.emit (events.js:42:17)
at Array.0 (net.js:799:27)
at EventEmitter._tickCallback (node.js:108:26)

I have still the same problem while talking with a Python Gevent SSL server.

Addition: It works with the 0.4.2 release but not with the v4.0 head anymore.

twills commented Mar 17, 2011

So you are saying that you do not see the problem with node 0.4.2? If that is the case, I will try 0.4.2 and see if it is fixed for me as well.

Yes exactly try if it works for you with 0.4.2.

@ry ry reopened this Mar 18, 2011

ry commented Mar 18, 2011

need a reproducible test. also we just landed an important fix
66570c1

please try again with v0.4 HEAD or v0.4.3 which I will release today.

No unfortunately not. Still not fixed for me while testing an https connection with a Python Gevent server. The server complains: "error: [Errno 104] Connection reset by peer"

twills commented Mar 18, 2011

Hi webholics, so do I understand correctly that you are saying now that you are still seeing the problem in 0.4.2? Are you able to provide a reproducible test case? It is going to be difficult for me as the servers I am seeing this with are not under my control, but I will see if I can come up with something.

No for me the error is there with the current v0.4 HEAD but not for 0.4.2. So please test with the 0.4.2 release if that version works for you.

twills commented Mar 18, 2011

OK, I will try it. Probably will wait for v0.4.3 though since that is going to be available soon.

jeremys commented Apr 6, 2011

@ry: here is a test that trigger the error each time: https://gist.github.com/901709

@ghost

ghost commented Apr 8, 2011

I don't know if this helps. Without Content-Length I get this error.
With Content-Length the error changed to 'socket hang up'.

@ghost ghost assigned ry Apr 11, 2011

ry commented Apr 11, 2011

@jeremys, I can reproduce from that, thanks. Attempting to make a test out of it...

ry commented Apr 11, 2011

I've pushed out a tentative fix in 9ccf0e5. I haven't been able to come up with a way to reproduce locally

Still no change for me, still getting:

TypeError: Cannot call method 'emit' of undefined
at CleartextStream. (http.js:1201:9)
at CleartextStream.emit (events.js:64:17)
at Socket.onerror (tls.js:874:17)
at Socket.emit (events.js:64:17)
at Array. (net.js:824:27)
at EventEmitter._tickCallback (node.js:126:26)

jeremys commented Apr 12, 2011

@webholics: Is it failing with the gist I provided? https://gist.github.com/901709 If not, could you provide a way to reproduce the issue?

For me, I can't reproduce this bug now.

Ok your gist doesn't fail for me either. Its the setTimeout(..., 0); which fixes the error for me.
But why? This is still a bug, isn't it?

jeremys commented Apr 12, 2011

So you mean with my gist without setTimeout you still have the error? Are you sure you are on the v0.4 branch?

Update: It seems fixed for me with any external HTTPS server but not for https://localhost:443.
In 9 out of 10 cases this crashes with the emit of undefined error.
Is it possible that because of local "connection speed" and reduced round trip time the server-client-handshake gets somehow confused?

@jeremys
Your gist works for me too but not for localhost.
I thought the reason was setTimeout because the error was not raised everytime anymore. But the setTimeout doesn't matter.

ry commented Apr 12, 2011

@webholics, is it possible to distil that down into something i can test?

@ry I've created a full test which fails roughly 1 out of 10. Unfortunately you have to install Python gevent locally.
https://gist.github.com/915603

ry commented Apr 12, 2011

@webholics, I can't repeat. If you can please strace the error occuring

That is all I get:

node.js:134
        throw e; // process.nextTick error, or 'error' event on first tick
        ^
TypeError: Cannot call method 'emit' of undefined
    at CleartextStream. (http.js:1201:9)
    at CleartextStream.emit (events.js:81:20)
    at Socket.onerror (tls.js:874:17)
    at Socket.emit (events.js:64:17)
    at Array. (net.js:824:27)
    at EventEmitter._tickCallback (node.js:126:26)

marsch commented Apr 13, 2011

mmhh today i ran in the same issue, so i played with this: https://gist.github.com/915603

in the http.js below (1187 (4.5)) [...]socket.on('error'[...], i found this nice statement:

// No requests on queue? Where is the request
assert(0);

so just added another nice statement above:

  // nothing? so just get out here 
  return;
  // No requests on queue? Where is the request
  assert(0);

i do not really exactly know whats goin on here. Perhaps the server closes the socket to early. But for me this return-statement made my day. can you copy that?

marsch commented Apr 13, 2011

i know there is an error. but for me it seems to be obvious:

'ENOTCONN, Transport endpoint is not connected',

that you can't write an error back to the client in this case, or am i mixin something?

ry commented Apr 13, 2011

@marsh, 9ccf0e5 should fix that - update to v0.4 head

marsch commented Apr 13, 2011

@ry thank :D

Is this bug now fixed for all of you? Because for me it is definitely not.

the latest 0.4.6 fixed the bug for me

@marsch I played again with https://gist.github.com/915603 and added your return statement before assert(0); in http.js

Now I'm able to catch the error with response.socket.on('error',..). It returns the following error:

{ stack: [Getter/Setter],
  arguments: undefined,
  type: undefined,
  message: 'ECONNRESET, Connection reset by peer',
  errno: 104,
  code: 'ECONNRESET',
  syscall: 'read' }

Maybe this helps?

@ry ry added a commit that referenced this issue Apr 14, 2011

@ry ry Don't emit error on ECONNRESET - just close
Fix #670
8417870

ry commented Apr 14, 2011

please try the above patch

Great, seems fixed for me now, too. I can't reproduce the error anymore.

twills commented Apr 15, 2011

I've updated to v0.4 HEAD and am still occasionally seeing this error. Stack trace follows. Once again, unfortunately I do not control the server side of the conversation, so I am not exactly sure what is happening or how to reproduce it, but it does seem that there is still an error condition out there which is not being handled.

TypeError: Cannot call method 'emit' of undefined
at CleartextStream. (http.js:1202:9)
at CleartextStream.emit (events.js:64:17)
at Socket.onerror (tls.js:888:17)
at Socket.emit (events.js:64:17)
at Array. (net.js:828:27)
at EventEmitter._tickCallback (node.js:126:26)

I get the same error on node v0.4.6

Stack trace: TypeError: Cannot call method 'emit' of undefined
at CleartextStream. (http.js:1202:9)
at CleartextStream.emit (events.js:64:17)
at Socket.onerror (tls.js:888:17)
at Socket.emit (events.js:64:17)
at Array. (net.js:824:27)
at EventEmitter._tickCallback (node.js:126:26)

sh1mmer commented Oct 24, 2011

Can someone try this with 0.5 HEAD? Otherwise I'd like to close it.

aseemk commented Nov 10, 2011

+1

Owner

bnoordhuis commented Feb 17, 2012

Closing, stale (and fixed). If anyone is still experiencing issues, please report them.

@bnoordhuis bnoordhuis closed this Feb 17, 2012

@twills twills unassigned ry Aug 31, 2015

@Trott Trott added a commit to Trott/io.js that referenced this issue Sep 12, 2015

@Trott Trott test: remove disabled test
Remove test file that has been in disabled from its very first commit
(9ccf0e5) in 2011. It is a test for
nodejs/node-v0.x-archive#670 from 2011. There
are no assertions in the test. In that regard, it is more debugging code
than a test.
88250c6

@Trott Trott referenced this issue in nodejs/node Sep 12, 2015

Closed

test: remove disabled test #2841

@Trott Trott added a commit to nodejs/node that referenced this issue Sep 14, 2015

@Trott Trott test: remove disabled test
Remove test file that has been in disabled from its very first commit
(9ccf0e5) in 2011. It is a test for
nodejs/node-v0.x-archive#670 from 2011. There
are no assertions in the test. In that regard, it is more debugging code
than a test.

PR-URL: #2841
Reviewed-By: Brian White <mscdex@mscdex.net>
Reviewed-By: Yosuke Furukawa <yosuke.furukawa@gmail.com>
999d25b

@Trott Trott added a commit to nodejs/node that referenced this issue Sep 15, 2015

@Trott @Fishrock123 Trott + Fishrock123 test: remove disabled test
Remove test file that has been in disabled from its very first commit
(9ccf0e5) in 2011. It is a test for
nodejs/node-v0.x-archive#670 from 2011. There
are no assertions in the test. In that regard, it is more debugging code
than a test.

PR-URL: #2841
Reviewed-By: Brian White <mscdex@mscdex.net>
Reviewed-By: Yosuke Furukawa <yosuke.furukawa@gmail.com>
5df5d04

@Trott Trott added a commit to nodejs/node that referenced this issue Sep 15, 2015

@Trott @rvagg Trott + rvagg test: remove disabled test
Remove test file that has been in disabled from its very first commit
(9ccf0e5) in 2011. It is a test for
nodejs/node-v0.x-archive#670 from 2011. There
are no assertions in the test. In that regard, it is more debugging code
than a test.

PR-URL: #2841
Reviewed-By: Brian White <mscdex@mscdex.net>
Reviewed-By: Yosuke Furukawa <yosuke.furukawa@gmail.com>
993c22f
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment