8000 Merge pull request #258 from osher/patch-4 · yanxi123-com/log4js-node@ec5f448 · GitHub
[go: up one dir, main page]
Skip to content

Commit ec5f448

Browse files
nomiddlenamenomiddlename
committed
Merge pull request log4js-node#258 from osher/patch-4
fix bug: headers are changed after log entry emits
2 parents 176d448 + 2f44dbf commit ec5f448

File tree

3 files changed

+89
-30
lines changed

3 files changed

+89
-30
lines changed

‎lib/connect-logger.js

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -56,7 +56,6 @@ function getLogger(logger4js, options) {
5656
var start = new Date()
5757
, statusCode
5858
, writeHead = res.writeHead
59-
, end = res.end
6059
, url = req.originalUrl;
6160

6261
// flag as logging
@@ -79,10 +78,8 @@ function getLogger(logger4js, options) {
7978
}
8079
};
8180

82-
// proxy end to output a line to the provided logger.
83-
res.end = function(chunk, encoding) {
84-
res.end = end;
85-
res.end(chunk, encoding);
81+
//hook on end request to emit the log entry of the HTTP request.
82+
res.on('finish', function() {
8683
res.responseTime = new Date() - start;
8784
//status code response level handling
8885
if(res.statusCode && options.level === 'auto'){
@@ -98,7 +95,7 @@ function getLogger(logger4js, options) {
9895
thislogger.log(level, format(fmt, req, res));
9996
}
10097
}
101-
};
98+
});
10299
}
103100

104101
//ensure next gets always called

‎test/connect-logger-test.js

Lines changed: 37 additi F438 ons & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,8 @@
22
"use strict";
33
var vows = require('vows')
44
, assert = require('assert')
5+
, util = require('util')
6+
, EE = require('events').EventEmitter
57
, levels = require('../lib/levels');
68

79
function MockLogger() {
@@ -37,15 +39,19 @@ function MockRequest(remoteAddr, method, originalUrl, headers) {
3739
}
3840

3941
function MockResponse() {
40-
41-
this.end = function(chunk, encoding) {
42+
var r = this;
43+
this.end = function(chunk, encoding) {
44+
r.emit('finish');
4245
};
4346

4447
this.writeHead = function(code, headers) {
48+
this.statusCode = code;
49+
this._headers = headers;
4550
};
46-
4751
}
4852

53+
util.inherits(MockResponse, EE);
54+
4955
function request(cl, method, url, code, reqHeaders, resHeaders) {
5056
var req = new MockRequest('my.remote.addr', method, url, reqHeaders);
5157
var res = new MockResponse();
@@ -81,8 +87,11 @@ vows.describe('log4js connect logger').addBatch({
8187
topic: function(clm) {
8288
var ml = new MockLogger();
8389
var cl = clm.connectLogger(ml);
90+
var cb = this.callback;
8491
request(cl, 'GET', 'http://url', 200);
85-
return ml.messages;
92+
setTimeout(function() {
93+
cb(null, ml.messages);
94+
},10);
8695
},
8796

8897
'check message': function(messages) {
@@ -114,11 +123,13 @@ vows.describe('log4js connect logger').addBatch({
114123
'log events with non-default level and custom format' : {
115124
topic: function(clm) {
116125
var ml = new MockLogger();
126+
var cb = this.callback;
117127
ml.level = levels.INFO;
118128
var cl = clm.connectLogger(ml, { level: levels.INFO, format: ':method :url' } );
119129
request(cl, 'GET', 'http://url', 200);
120-
return ml.messages;
121-
},
130+
setTimeout(function() {
131+
cb(null, ml.messages);
132+
},10); },
122133

123134
'check message': function(messages) {
124135
assert.isArray(messages);
@@ -131,10 +142,13 @@ vows.describe('log4js connect logger').addBatch({
131142
'logger with options as string': {
132143
topic: function(clm) {
133144
var ml = new MockLogger();
145+
var cb = this.callback;
134146
ml.level = levels.INFO;
135147
var cl = clm.connectLogger(ml, ':method :url');
136148
request(cl, 'POST', 'http://meh', 200);
137-
return ml.messages;
149+
setTimeout(function() {
150+
cb(null, ml.messages);
151+
},10);
138152
},
139153
'should use the passed in format': function(messages) {
140154
assert.equal(messages[0].message, 'POST http://meh');
@@ -144,14 +158,17 @@ vows.describe('log4js connect logger').addBatch({
144158
'auto log levels': {
145159
topic: function(clm) {
146160
var ml = new MockLogger();
161+
var cb = this.callback;
147162
ml.level = levels.INFO;
148163
var cl = clm.connectLogger(ml, { level: 'auto', format: ':method :url' });
149164
request(cl, 'GET', 'http://meh', 200);
150165
request(cl, 'GET', 'http://meh', 201);
151166
request(cl, 'GET', 'http://meh', 302);
152167
request(cl, 'GET', 'http://meh', 404);
153168
request(cl, 'GET', 'http://meh', 500);
154-
return ml.messages;
169+
setTimeout(function() {
170+
cb(null, ml.messages);
171+
},10);
155172
},
156173

157174
'should use INFO for 2xx': function(messages) {
@@ -175,10 +192,13 @@ vows.describe('log4js connect logger').addBatch({
175192
'format using a function': {
176193
topic: function(clm) {
177194
var ml = new MockLogger();
195+
var cb = this.callback;
178196
ml.level = levels.INFO;
179197
var cl = clm.connectLogger(ml, function(req, res, formatFn) { return "I was called"; });
180198
request(cl, 'GET', 'http://blah', 200);
181-
return ml.messages;
199+
setTimeout(function() {
200+
cb(null, ml.messages);
201+
},10);
182202
},
183203

184204
'should call the format function': function(messages) {
@@ -189,14 +209,17 @@ vows.describe('log4js connect logger').addBatch({
189209
'format that includes request headers': {
190210
topic: function(clm) {
191211
var ml = new MockLogger();
212+
var cb = this.callback;
192213
ml.level = levels.INFO;
193214
var cl = clm.connectLogger(ml, ':req[Content-Type]');
194215
request(
195216
cl,
196217
'GET', 'http://blah', 200,
197218
{ 'Content-Type': 'application/json' }
198219
);
199-
return ml.messages;
220+
setTimeout(function() {
221+
cb(null, ml.messages);
222+
},10);
200223
},
201224
'should output the request header': function(messages) {
202225
assert.equal(messages[0].message, 'application/json');
@@ -206,6 +229,7 @@ vows.describe('log4js connect logger').addBatch({
206229
'format that includes response headers': {
207230
topic: function(clm) {
208231
var ml = new MockLogger();
232+
var cb = this.callback;
209233
ml.level = levels.INFO;
210234
var cl = clm.connectLogger(ml, ':res[Content-Type]');
211235
request(
@@ -214,7 +238,9 @@ vows.describe('log4js connect logger').addBatch({
214238
null,
215239
{ 'Content-Type': 'application/cheese' }
216240
);
217-
return ml.messages;
241+
setTimeout(function() {
242+
cb(null, ml.messages);
243+
},10);
218244
},
219245

220246
'should output the response header': function(messages) {

‎test/nolog-test.js

Lines changed: 49 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,8 @@
11
"use strict";
22
var vows = require('vows')
33
, assert = require('assert')
4+
, util = require('util')
5+
, EE = require('events').EventEmitter
46
, levels = require('../lib/levels');
57

68
function MockLogger() {
@@ -31,13 +33,14 @@ function MockRequest(remoteAddr, method, originalUrl) {
3133
}
3234

3335
function MockResponse(statusCode) {
34-
36+
var r = this;
3537
this.statusCode = statusCode;
3638

3739
this.end = function(chunk, encoding) {
38-
40+
r.emit('finish');
3941
};
4042
}
43+
util.inherits(MockResponse, EE);
4144

4245
vows.describe('log4js connect logger').addBatch({
4346
'getConnectLoggerModule': {
@@ -61,9 +64,12 @@ vows.describe('log4js connect logger').addBatch({
6164
topic: function(d){
6265
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
6366
var res = new MockResponse(200);
67+
var cb = this.callback;
6468
d.cl(req, res, function() { });
6569
res.end('chunk', 'encoding');
66-
return d.ml.messages;
70+
setTimeout(function() {
71+
cb(null, d.ml.messages);
72+
},10);
6773
},
6874
'check message': function(messages){
6975
assert.isArray(messages);
@@ -81,9 +87,12 @@ vows.describe('log4js connect logger').addBatch({
8187
topic: function(d) {
8288
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
8389
var res = new MockResponse(200);
90+
var cb = this.callback;
8491
d.cl(req, res, function() { });
8592
res.end('chunk', 'encoding');
86-
return d.ml.messages;
93+
setTimeout(function() {
94+
cb(null, d.ml.messages);
95+
},10);
8796
},
8897
'check message': function(messages) {
8998
assert.isArray(messages);
@@ -103,9 +112,12 @@ vows.describe('log4js connect logger').addBatch({
103112
topic: function(d){
104113
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
105114
var res = new MockResponse(200);
115+
var cb = this.callback;
106116
d.cl(req, res, function() { });
107117
res.end('chunk', 'encoding');
108-
return d.ml.messages;
118+
setTimeout(function() {
119+
cb(null, d.ml.messages)
120+
}, 10);
109121
},
110122
'check message': function(messages){
111123
assert.isArray(messages);
@@ -123,9 +135,12 @@ vows.describe('log4js connect logger').addBatch({
123135
topic: function(d) {
124136
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
125137
var res = new MockResponse(200);
138+
var cb = this.callback;
126139
d.cl(req, res, function() { });
127140
res.end('chunk', 'encoding');
128-
return d.ml.messages;
141+
setTimeout(function() {
142+
cb(null, d.ml.messages)
143+
}, 10);
129144
},
130145
'check message': function(messages) {
131146
assert.isArray(messages);
@@ -136,9 +151,12 @@ vows.describe('log4js connect logger').addBatch({
136151
topic: function(d) {
137152
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
138153
var res = new MockResponse(200);
154+
var cb = this.callback;
139155
d.cl(req, res, function() { });
140156
res.end('chunk', 'encoding');
141-
return d.ml.messages;
157+
setTimeout(function() {
158+
cb(null, d.ml.messages)
159+
}, 10);
142160
},
143161
'check message': function(messages) {
144162
assert.isArray(messages);
@@ -157,9 +175,12 @@ vows.describe('log4js connect logger').addBatch({
157175
topic: function(d){
158176
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
159177
var res = new MockResponse(200);
178+
var cb = this.callback;
160179
d.cl(req, res, function() { });
161180
res.end('chunk', 'encoding');
162-
return d.ml.messages;
181+
setTimeout(function() {
182+
cb(null, d.ml.messages)
183+
}, 10);
163184
},
164185
'check message': function(messages){
165186
assert.isArray(messages);
@@ -177,9 +198,12 @@ vows.describe('log4js connect logger').addBatch({
177198
topic: function(d) {
178199
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
179200
var res = new MockResponse(200);
201+
var cb = this.callback;
180202
d.cl(req, res, function() { });
181203
res.end('chunk', 'encoding');
182-
return d.ml.messages;
204+
setTimeout(function() {
205+
cb(null, d.ml.messages)
206+
}, 10);
183207
},
184208
'check message': function(messages) {
185209
assert.isArray(messages);
@@ -191,9 +215,12 @@ vows.describe('log4js connect logger').addBatch({
191215
topic: function(d) {
192216
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
193217
var res = new MockResponse(200);
218+
var cb = this.callback;
194219
d.cl(req, res, function() { });
195220
res.end('chunk', 'encoding');
196-
return d.ml.messages;
221+
setTimeout(function() {
222+
cb(null, d.ml.messages)
223+
}, 10);
197224
},
198225
'check message': function(messages) {
199226
assert.isArray(messages);
@@ -212,9 +239,12 @@ vows.describe('log4js connect logger').addBatch({
212239
topic: function(d){
213240
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.png'); // not gif
214241
var res = new MockResponse(200);
242+
var cb = this.callback;
215243
d.cl(req, res, function() { });
216244
res.end('chunk', 'encoding');
217-
return d.ml.messages;
245+
setTimeout(function() {
246+
cb(null, d.ml.messages)
247+
}, 10);
218248
},
219249
'check message': function(messages){
220250
assert.isArray(messages);
@@ -232,9 +262,12 @@ vows.describe('log4js connect logger').addBatch({
232262
topic: function(d) {
233263
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.gif'); // gif
234264
var res = new MockResponse(200);
265+
var cb = this.callback;
235266
d.cl(req, res, function() { });
236267
res.end('chunk', 'encoding');
237-
return d.ml.messages;
268+
setTimeout(function() {
269+
cb(null, d.ml.messages)
270+
}, 10);
238271
},
239272
'check message': function(messages) {
240273
assert.isArray(messages);
@@ -246,9 +279,12 @@ vows.describe('log4js connect logger').addBatch({
246279
topic: function(d) {
247280
var req = new MockRequest('my.remote.addr', 'GET', 'http://url/hoge.jpeg'); // gif
248281
var res = new MockResponse(200);
282+
var cb = this.callback;
249283
d.cl(req, res, function() { });
250284
res.end('chunk', 'encoding');
251-
return d.ml.messages;
285+
setTimeout(function() {
286+
cb(null, d.ml.messages)
287+
}, 10);
252288
},
253289
'check message': function(messages) {
254290
assert.isArray(messages);

0 commit comments

Comments
 (0)
0