Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit00f6846

Browse files
addaleaxBethGriggs
authored andcommitted
http2: improve JS-side debug logging
DRY up the `debug()` calls, and in particular, avoid building templatestrings before we know whether we need to.Backport-PR-URL:#29124PR-URL:#29122Reviewed-By: Rich Trott <rtrott@gmail.com>Reviewed-By: James M Snell <jasnell@gmail.com>
1 parent6d42737 commit00f6846

File tree

1 file changed

+61
-54
lines changed

1 file changed

+61
-54
lines changed

‎lib/internal/http2/core.js‎

Lines changed: 61 additions & 54 deletions
Original file line numberDiff line numberDiff line change
@@ -64,6 +64,26 @@ const { createPromise, promiseResolve } = process.binding('util');
6464
const{_connectionListener:httpConnectionListener}=http;
6565
constdebug=util.debuglog('http2');
6666

67+
// TODO(addaleax): See if this can be made more efficient by figuring out
68+
// whether debugging is enabled before we perform any further steps. Currently,
69+
// this seems pretty fast, though.
70+
functiondebugStream(id,sessionType,message, ...args){
71+
debug('Http2Stream %s [Http2Session %s]: '+message,
72+
id,sessionName(sessionType), ...args);
73+
}
74+
75+
functiondebugStreamObj(stream,message, ...args){
76+
debugStream(stream[kID],stream[kSession][kType], ...args);
77+
}
78+
79+
functiondebugSession(sessionType,message, ...args){
80+
debug('Http2Session %s: '+message,sessionName(sessionType), ...args);
81+
}
82+
83+
functiondebugSessionObj(session,message, ...args){
84+
debugSession(session[kType],message, ...args);
85+
}
86+
6787
constkMaxFrameSize=(2**24)-1;
6888
constkMaxInt=(2**32)-1;
6989
constkMaxStreams=(2**31)-1;
@@ -189,8 +209,7 @@ function onSessionHeaders(handle, id, cat, flags, headers) {
189209

190210
consttype=session[kType];
191211
session[kUpdateTimer]();
192-
debug(`Http2Stream${id} [Http2Session `+
193-
`${sessionName(type)}]: headers received`);
212+
debugStream(id,type,'headers received');
194213
conststreams=session[kState].streams;
195214

196215
constendOfStream=!!(flags&NGHTTP2_FLAG_END_STREAM);
@@ -250,8 +269,7 @@ function onSessionHeaders(handle, id, cat, flags, headers) {
250269
constoriginSet=session[kState].originSet=initOriginSet(session);
251270
originSet.delete(stream[kOrigin]);
252271
}
253-
debug(`Http2Stream${id} [Http2Session `+
254-
`${sessionName(type)}]: emitting stream '${event}' event`);
272+
debugStream(id,type,"emitting stream '%s' event",event);
255273
process.nextTick(emit,stream,event,obj,flags,headers);
256274
}
257275
if(endOfStream){
@@ -292,7 +310,7 @@ function onPing(payload) {
292310
if(session.destroyed)
293311
return;
294312
session[kUpdateTimer]();
295-
debug(`Http2Session${sessionName(session[kType])}:new ping received`);
313+
debugSessionObj(session,'new ping received');
296314
session.emit('ping',payload);
297315
}
298316

@@ -307,8 +325,7 @@ function onStreamClose(code) {
307325
if(stream.destroyed)
308326
return;
309327

310-
debug(`Http2Stream${stream[kID]} [Http2Session `+
311-
`${sessionName(stream[kSession][kType])}]: closed with code${code}`);
328+
debugStreamObj(stream,'closed with code %d',code);
312329

313330
if(!stream.closed)
314331
closeStream(stream,code,kNoRstStream);
@@ -376,7 +393,7 @@ function onSettings() {
376393
if(session.destroyed)
377394
return;
378395
session[kUpdateTimer]();
379-
debug(`Http2Session${sessionName(session[kType])}:new settings received`);
396+
debugSessionObj(session,'new settings received');
380397
session[kRemoteSettings]=undefined;
381398
session.emit('remoteSettings',session.remoteSettings);
382399
}
@@ -388,9 +405,9 @@ function onPriority(id, parent, weight, exclusive) {
388405
constsession=this[kOwner];
389406
if(session.destroyed)
390407
return;
391-
debug(`Http2Stream${id} [Http2Session `+
392-
`${sessionName(session[kType])}]:priority [parent:${parent}, `+
393-
`weight:${weight}, exclusive:${exclusive}]`);
408+
debugStream(id,session[kType],
409+
'priority [parent:%d, weight: %d, exclusive: %s]',
410+
parent,weight,exclusive);
394411
constemitter=session[kState].streams.get(id)||session;
395412
if(!emitter.destroyed){
396413
emitter[kUpdateTimer]();
@@ -404,8 +421,8 @@ function onFrameError(id, type, code) {
404421
constsession=this[kOwner];
405422
if(session.destroyed)
406423
return;
407-
debug(`Http2Session${sessionName(session[kType])}:error sending frame`+
408-
`type${type} on stream${id}, code:${code}`);
424+
debugSessionObj(session,'error sending frametype %d on stream %d, code: %d',
425+
type,id,code);
409426
constemitter=session[kState].streams.get(id)||session;
410427
emitter[kUpdateTimer]();
411428
emitter.emit('frameError',type,code,id);
@@ -415,8 +432,8 @@ function onAltSvc(stream, origin, alt) {
415432
constsession=this[kOwner];
416433
if(session.destroyed)
417434
return;
418-
debug(`Http2Session${sessionName(session[kType])}:altsvc received:`+
419-
`stream:${stream}, origin:${origin}, alt:${alt}`);
435+
debugSessionObj(session,'altsvc received:stream: %d, origin: %s, alt: %s',
436+
stream,origin,alt);
420437
session[kUpdateTimer]();
421438
session.emit('altsvc',alt,origin,stream);
422439
}
@@ -443,8 +460,7 @@ function onOrigin(origins) {
443460
constsession=this[kOwner];
444461
if(session.destroyed)
445462
return;
446-
debug(`Http2Session${sessionName(session[kType])}: origin received: `+
447-
`${origins.join(', ')}`);
463+
debugSessionObj(session,'origin received: %j',origins);
448464
session[kUpdateTimer]();
449465
if(!session.encrypted||session.destroyed)
450466
returnundefined;
@@ -464,8 +480,8 @@ function onGoawayData(code, lastStreamID, buf) {
464480
constsession=this[kOwner];
465481
if(session.destroyed)
466482
return;
467-
debug(`Http2Session${sessionName(session[kType])}:goaway${code} `+
468-
`received [last stream id:${lastStreamID}]`);
483+
debugSessionObj(session,'goaway%d received [last stream id: %d]',
484+
code,lastStreamID);
469485

470486
conststate=session[kState];
471487
state.goawayCode=code;
@@ -519,8 +535,7 @@ function requestOnConnect(headers, options) {
519535
return;
520536
}
521537

522-
debug(`Http2Session${sessionName(session[kType])}: connected, `+
523-
'initializing request');
538+
debugSessionObj(session,'connected, initializing request');
524539

525540
letstreamOptions=0;
526541
if(options.endStream)
@@ -623,13 +638,13 @@ function settingsCallback(cb, ack, duration) {
623638
this[kState].pendingAck--;
624639
this[kLocalSettings]=undefined;
625640
if(ack){
626-
debug(`Http2Session${sessionName(this[kType])}:settings received`);
641+
debugSessionObj(this,'settings received');
627642
constsettings=this.localSettings;
628643
if(typeofcb==='function')
629644
cb(null,settings,duration);
630645
this.emit('localSettings',settings);
631646
}else{
632-
debug(`Http2Session${sessionName(this[kType])}:settings canceled`);
647+
debugSessionObj(this,'settings canceled');
633648
if(typeofcb==='function')
634649
cb(newerrors.Error('ERR_HTTP2_SETTINGS_CANCEL'));
635650
}
@@ -639,7 +654,7 @@ function settingsCallback(cb, ack, duration) {
639654
functionsubmitSettings(settings,callback){
640655
if(this.destroyed)
641656
return;
642-
debug(`Http2Session${sessionName(this[kType])}:submitting settings`);
657+
debugSessionObj(this,'submitting settings');
643658
this[kUpdateTimer]();
644659
updateSettingsBuffer(settings);
645660
if(!this[kHandle].settings(settingsCallback.bind(this,callback))){
@@ -673,7 +688,7 @@ function submitPriority(options) {
673688
functionsubmitGoaway(code,lastStreamID,opaqueData){
674689
if(this.destroyed)
675690
return;
676-
debug(`Http2Session${sessionName(this[kType])}:submitting goaway`);
691+
debugSessionObj(this,'submitting goaway');
677692
this[kUpdateTimer]();
678693
this[kHandle].goaway(code,lastStreamID,opaqueData);
679694
}
@@ -803,7 +818,9 @@ function setupHandle(socket, type, options) {
803818
process.nextTick(emit,this,'connect',this,socket);
804819
return;
805820
}
806-
debug(`Http2Session${sessionName(type)}: setting up session handle`);
821+
822+
debugSession(type,'setting up session handle');
823+
807824
this[kState].flags|=SESSION_FLAGS_READY;
808825

809826
updateOptionsBuffer(options);
@@ -964,7 +981,7 @@ class Http2Session extends EventEmitter {
964981
setupFn();
965982
}
966983

967-
debug(`Http2Session${sessionName(type)}:created`);
984+
debugSession(type,'created');
968985
}
969986

970987
// Returns undefined if the socket is not yet connected, true if the
@@ -1138,7 +1155,7 @@ class Http2Session extends EventEmitter {
11381155

11391156
if(callback&&typeofcallback!=='function')
11401157
thrownewerrors.TypeError('ERR_INVALID_CALLBACK');
1141-
debug(`Http2Session${sessionName(this[kType])}:sending settings`);
1158+
debugSessionObj(this,'sending settings');
11421159

11431160
this[kState].pendingAck++;
11441161

@@ -1184,7 +1201,7 @@ class Http2Session extends EventEmitter {
11841201
destroy(error=NGHTTP2_NO_ERROR,code){
11851202
if(this.destroyed)
11861203
return;
1187-
debug(`Http2Session${sessionName(this[kType])}:destroying`);
1204+
debugSessionObj(this,'destroying');
11881205

11891206
if(typeoferror==='number'){
11901207
code=error;
@@ -1245,7 +1262,7 @@ class Http2Session extends EventEmitter {
12451262
close(callback){
12461263
if(this.closed||this.destroyed)
12471264
return;
1248-
debug(`Http2Session${sessionName(this[kType])}:marking session closed`);
1265+
debugSessionObj(this,'marking session closed');
12491266
this[kState].flags|=SESSION_FLAGS_CLOSED;
12501267
if(typeofcallback==='function')
12511268
this.once('close',callback);
@@ -1415,7 +1432,7 @@ class ClientHttp2Session extends Http2Session {
14151432
// Submits a new HTTP2 request to the connected peer. Returns the
14161433
// associated Http2Stream instance.
14171434
request(headers,options){
1418-
debug(`Http2Session${sessionName(this[kType])}:initiating request`);
1435+
debugSessionObj(this,'initiating request');
14191436

14201437
if(this.destroyed)
14211438
thrownewerrors.Error('ERR_HTTP2_INVALID_SESSION');
@@ -1843,8 +1860,7 @@ class Http2Stream extends Duplex {
18431860
if(this[kID]===undefined){
18441861
this.once('ready',()=>this._final(cb));
18451862
}elseif(handle!==undefined){
1846-
debug(`Http2Stream${this[kID]} [Http2Session `+
1847-
`${sessionName(this[kSession][kType])}]: _final shutting down`);
1863+
debugStreamObj(this,'_final shutting down');
18481864
constreq=newShutdownWrap();
18491865
req.oncomplete=afterShutdown;
18501866
req.callback=cb;
@@ -1901,9 +1917,7 @@ class Http2Stream extends Duplex {
19011917
assertIsObject(headers,'headers');
19021918
headers=Object.assign(Object.create(null),headers);
19031919

1904-
constsession=this[kSession];
1905-
debug(`Http2Stream${this[kID]} [Http2Session `+
1906-
`${sessionName(session[kType])}]: sending trailers`);
1920+
debugStreamObj(this,'sending trailers');
19071921

19081922
this[kUpdateTimer]();
19091923

@@ -1959,8 +1973,8 @@ class Http2Stream extends Duplex {
19591973
consthandle=this[kHandle];
19601974
constid=this[kID];
19611975

1962-
debug(`Http2Stream${this[kID]||'<pending>'} [Http2Session `+
1963-
`${sessionName(session[kType])}]: destroying stream`);
1976+
debugStream(this[kID]||'pending',session[kType],'destroying stream');
1977+
19641978
conststate=this[kState];
19651979
constcode=err!=null ?
19661980
NGHTTP2_INTERNAL_ERROR :(state.rstCode||NGHTTP2_NO_ERROR);
@@ -2232,8 +2246,7 @@ class ServerHttp2Stream extends Http2Stream {
22322246

22332247
constsession=this[kSession];
22342248

2235-
debug(`Http2Stream${this[kID]} [Http2Session `+
2236-
`${sessionName(session[kType])}]: initiating push stream`);
2249+
debugStreamObj(this,'initiating push stream');
22372250

22382251
this[kUpdateTimer]();
22392252

@@ -2315,9 +2328,7 @@ class ServerHttp2Stream extends Http2Stream {
23152328
assertIsObject(options,'options');
23162329
options=Object.assign({},options);
23172330

2318-
constsession=this[kSession];
2319-
debug(`Http2Stream${this[kID]} [Http2Session `+
2320-
`${sessionName(session[kType])}]: initiating response`);
2331+
debugStreamObj(this,'initiating response');
23212332
this[kUpdateTimer]();
23222333

23232334
options.endStream=!!options.endStream;
@@ -2404,8 +2415,7 @@ class ServerHttp2Stream extends Http2Stream {
24042415
thrownewerrors.TypeError('ERR_INVALID_ARG_TYPE',
24052416
'fd','number');
24062417

2407-
debug(`Http2Stream${this[kID]} [Http2Session `+
2408-
`${sessionName(session[kType])}]: initiating response`);
2418+
debugStreamObj(this,'initiating response from fd');
24092419
this[kUpdateTimer]();
24102420

24112421
headers=processHeaders(headers);
@@ -2470,8 +2480,7 @@ class ServerHttp2Stream extends Http2Stream {
24702480
}
24712481

24722482
constsession=this[kSession];
2473-
debug(`Http2Stream${this[kID]} [Http2Session `+
2474-
`${sessionName(session[kType])}]: initiating response`);
2483+
debugStreamObj(this,'initiating response from file');
24752484
this[kUpdateTimer]();
24762485

24772486

@@ -2504,9 +2513,7 @@ class ServerHttp2Stream extends Http2Stream {
25042513
assertIsObject(headers,'headers');
25052514
headers=Object.assign(Object.create(null),headers);
25062515

2507-
constsession=this[kSession];
2508-
debug(`Http2Stream${this[kID]} [Http2Session `+
2509-
`${sessionName(session[kType])}]: sending additional headers`);
2516+
debugStreamObj(this,'sending additional headers');
25102517

25112518
if(headers[HTTP2_HEADER_STATUS]!=null){
25122519
conststatusCode=headers[HTTP2_HEADER_STATUS]|=0;
@@ -2595,8 +2602,7 @@ function socketOnError(error) {
25952602
// we can do and the other side is fully within its rights to do so.
25962603
if(error.code==='ECONNRESET'&&session[kState].goawayCode!==null)
25972604
returnsession.destroy();
2598-
debug(`Http2Session${sessionName(session[kType])}: socket error [`+
2599-
`${error.message}]`);
2605+
debugSessionObj(this,'socket error [%s]',error.message);
26002606
session.destroy(error);
26012607
}
26022608
}
@@ -2641,7 +2647,8 @@ function connectionListener(socket) {
26412647
returnhttpConnectionListener.call(this,socket);
26422648
}
26432649
// Let event handler deal with the socket
2644-
debug(`Unknown protocol from${socket.remoteAddress}:${socket.remotePort}`);
2650+
debug('Unknown protocol from %s:%s',
2651+
socket.remoteAddress,socket.remotePort);
26452652
if(!this.emit('unknownProtocol',socket)){
26462653
// We don't know what to do, so let's just tell the other side what's
26472654
// going on in a format that they *might* understand.
@@ -2766,7 +2773,7 @@ function setupCompat(ev) {
27662773
functionsocketOnClose(){
27672774
constsession=this[kSession];
27682775
if(session!==undefined){
2769-
debug(`Http2Session${sessionName(session[kType])}:socket closed`);
2776+
debugSessionObj(session,'socket closed');
27702777
consterr=session.connecting ?
27712778
newerrors.Error('ERR_SOCKET_CLOSED') :null;
27722779
conststate=session[kState];

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp