fix bug: headers are changed after log entry emits #258
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
In the original version, the following operation looks synchronic, however it is not:
```
res.end = end;
res.end(data,enc);
//emit the log entry
```
In fact, it starts a series of async operations, in which the request may yet be changed after the request log has already been emitted
(in our case - a change
8000
on request headers was observed, probably by some low level hook or hacky wrap of some http.ServerResponse method that's involved on the process - but called asynchronously)
what leads to situation that the request log does not capture valid data.
(observed by us:
- request headers
- calculated end time, when concerning big content
)
The fix just used `setTimeout(function() { /*emit the log entry*/ }, 1)`, but I'm afraid it may not hold true for big contents.
Well. maybe the headers part will, but the response time calculation will lie.
The fix relays on: http://nodejs.org/api/http.html#http_event_finish
|
You got to be kidding But I'm on it. |
|
Ok, that does it :) |
|
I was worried in your description that you'd just put "setTimeout" in the code, but listening for the request "finish" event makes sense. Thanks. |
nomiddlename
added a commit
that referenced
this pull request
Nov 15, 2014
fix bug: headers are changed after log entry emits
|
I see this PR made it to the master branch, but it's yet to be published. Say, when do we expect the next version publish? |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
In the original version, the following operation looks synchronic, however it is not:
In fact, it starts a series of async operations, in which the request may yet be changed after the request log has already been emitted
(in our case - a change on request headers was observed, probably by some low level hook or hacky wrap of some http.ServerResponse method that's involved on the process - but called asynchronously)
what leads to situation that the request log does not capture valid data.
(observed by us:
)
First, the fix just used
setTimeout(function() { /*emit the log entry*/ }, 5), but I'm afraid it may not hold true for big contents.Well. maybe the headers part will, but the response time calculation will lie.
The fix relays on: http://nodejs.org/api/http.html#http_event_finish