From ad598ecbe494680cf5db170406f5862df54f848e Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 14:53:46 -0700 Subject: [PATCH 01/12] Serverside keepalive error detection and cleanups - Bugfix: Ensure that if session.ping returns false we correctly identify fail the keepalive and connection - Bugfix: Ensure that if the interval between keepalives being sent occurs faster than the prior keepalive's timeout that we do not overwrite the reference to the prior timeout. Prior implementation could have in theory prevented a valid keepalive timeout from clearing itself. This rewrite keeps every timeout as a local (vs a shared state per session). Even if the timeout outlives the lifetime of a session, we still guard against errors by checking that the parent interval is not false-y. I reckon this could result in a short-term memory leak per session which is bounded for a maximum of keepaliveTimeoutMs. On the other hand even with that potential for a short reference hold, this implementation proposed here is more correct I think. One alternative we could do is keep a list of pending timeouts.. which is complex for a rare situation that will self resolve anyhow when keepaliveTimeoutMs is reached. - Bug Fix: keepalive intervals were being cleared with an incorrect clearTimeout before. Not sure if this was causing intervals leaks in some nodejs impls or not. (v20.13.1 seems to accept this mismatch without issue) - Rename variables for clarity, to prevent future bugs like swapping clearInterval vs clearTimeout. - Implementation is repeated in two places, per warning from https://github.com/grpc/grpc-node/pull/2756#issuecomment-2136031256 - This commit supercedes the prior PR on a master branch which was out of date. https://github.com/grpc/grpc-node/pull/2756 --- packages/grpc-js/src/server.ts | 205 +++++++++++++++++++++------------ 1 file changed, 134 insertions(+), 71 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index feb511b41..c4d87af38 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1376,8 +1376,7 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; - let keeapliveTimeTimer: NodeJS.Timeout | null = null; - let keepaliveTimeoutTimer: NodeJS.Timeout | null = null; + let keepaliveInterval: NodeJS.Timeout | null = null; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1421,41 +1420,74 @@ export class Server { } if (this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS) { - keeapliveTimeTimer = setInterval(() => { - keepaliveTimeoutTimer = setTimeout(() => { - sessionClosedByServer = true; - session.close(); + keepaliveInterval = setInterval(() => { + // NOTE to self: document in PR that prior implementation would overwrite the prior pending timeout + // if the timeout had not occurred before the prior interval had elapsed (bad bug) + const keepaliveTimeout = setTimeout(() => { + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + sessionClosedByServer = true; + this.trace('Connection dropped by keepalive timeout'); + session.close(); + } }, this.keepaliveTimeoutMs); - keepaliveTimeoutTimer.unref?.(); + keepaliveTimeout.unref?.(); try { - session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - if (keepaliveTimeoutTimer) { - clearTimeout(keepaliveTimeoutTimer); + if ( + !session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearTimeout(keepaliveTimeout); + if (err) { + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + } + sessionClosedByServer = true; + this.trace( + 'Connection dropped due to error with ping frame ' + + err.message + + ' return in ' + + duration + ); + session.close(); + } } - - if (err) { - sessionClosedByServer = true; - this.trace( - 'Connection dropped due to error of a ping frame ' + - err.message + - ' return in ' + - duration - ); - session.close(); - } - } - ); + ) + ) { + throw new Error('Server keepalive ping send failed'); + } } catch (e) { - clearTimeout(keepaliveTimeoutTimer); - // The ping can't be sent because the session is already closed + // The ping can't be sent because the session is already closed, max outstanding pings reached, etc + clearTimeout(keepaliveTimeout); + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + } + this.trace( + 'Connection dropped due to error sending ping frame ' + + (e instanceof Error ? e.message : 'unknown error') + ); session.destroy(); } }, this.keepaliveTimeMs); - keeapliveTimeTimer.unref?.(); + keepaliveInterval.unref?.(); } + session.once('goaway', (errorCode, lastStreamID, opaqueData) => { + if (errorCode === http2.constants.NGHTTP2_ENHANCE_YOUR_CALM) { + this.trace('Connection dropped by client due to ENHANCE_YOUR_CALM'); + } else { + this.trace( + 'Connection dropped by client via GOAWAY with error code ' + + errorCode + ); + } + sessionClosedByServer = true; + session.destroy(); + }); + session.on('close', () => { if (!sessionClosedByServer) { this.trace( @@ -1471,11 +1503,9 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - if (keeapliveTimeTimer) { - clearInterval(keeapliveTimeTimer); - if (keepaliveTimeoutTimer) { - clearTimeout(keepaliveTimeoutTimer); - } + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; } if (idleTimeoutObj !== null) { @@ -1521,8 +1551,7 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; - let keeapliveTimeTimer: NodeJS.Timeout | null = null; - let keepaliveTimeoutTimer: NodeJS.Timeout | null = null; + let keepaliveInterval: NodeJS.Timeout | null = null; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1565,49 +1594,85 @@ export class Server { } if (this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS) { - keeapliveTimeTimer = setInterval(() => { - keepaliveTimeoutTimer = setTimeout(() => { - sessionClosedByServer = true; - this.channelzTrace.addTrace( - 'CT_INFO', - 'Connection dropped by keepalive timeout from ' + clientAddress - ); - - session.close(); + keepaliveInterval = setInterval(() => { + const keepaliveTimeout = setTimeout(() => { + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + sessionClosedByServer = true; + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped by keepalive timeout from ' + clientAddress + ); + session.close(); + } }, this.keepaliveTimeoutMs); - keepaliveTimeoutTimer.unref?.(); + keepaliveTimeout.unref?.(); try { - session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - if (keepaliveTimeoutTimer) { - clearTimeout(keepaliveTimeoutTimer); - } - - if (err) { - sessionClosedByServer = true; - this.channelzTrace.addTrace( - 'CT_INFO', - 'Connection dropped due to error of a ping frame ' + - err.message + - ' return in ' + - duration - ); - - session.close(); + if ( + !session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearTimeout(keepaliveTimeout); + if (err) { + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + } + sessionClosedByServer = true; + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped due to error with ping frame ' + + err.message + + ' return in ' + + duration + ); + session.close(); + } } - } - ); + ) + ) { + throw new Error('Server keepalive ping send failed'); + } channelzSessionInfo.keepAlivesSent += 1; } catch (e) { - clearTimeout(keepaliveTimeoutTimer); - // The ping can't be sent because the session is already closed + // The ping can't be sent because the session is already closed, max outstanding pings reached, etc + clearTimeout(keepaliveTimeout); + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; + } + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped due to error sending ping frame ' + + (e instanceof Error ? e.message : 'unknown error') + ); session.destroy(); } }, this.keepaliveTimeMs); - keeapliveTimeTimer.unref?.(); + keepaliveInterval.unref?.(); } + session.once('goaway', (errorCode, lastStreamID, opaqueData) => { + if (errorCode === http2.constants.NGHTTP2_ENHANCE_YOUR_CALM) { + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped by client due GOAWAY of ENHANCE_YOUR_CALM from ' + + clientAddress + ); + } else { + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped by client via GOAWAY with error code ' + + errorCode + + ' from ' + + clientAddress + ); + } + sessionClosedByServer = true; + session.destroy(); + }); + session.on('close', () => { if (!sessionClosedByServer) { this.channelzTrace.addTrace( @@ -1627,11 +1692,9 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - if (keeapliveTimeTimer) { - clearInterval(keeapliveTimeTimer); - if (keepaliveTimeoutTimer) { - clearTimeout(keepaliveTimeoutTimer); - } + if (keepaliveInterval) { + clearInterval(keepaliveInterval); + keepaliveInterval = null; } if (idleTimeoutObj !== null) { From 334f0dcdb5ecec9c7ece114f6d5cf8c7b0ca7ebc Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 14:58:59 -0700 Subject: [PATCH 02/12] remove comment --- packages/grpc-js/src/server.ts | 2 -- 1 file changed, 2 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index c4d87af38..aed65bbb0 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1421,8 +1421,6 @@ export class Server { if (this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS) { keepaliveInterval = setInterval(() => { - // NOTE to self: document in PR that prior implementation would overwrite the prior pending timeout - // if the timeout had not occurred before the prior interval had elapsed (bad bug) const keepaliveTimeout = setTimeout(() => { if (keepaliveInterval) { clearInterval(keepaliveInterval); From d799a7a5bdd372cabe5e3fdadbaf728448c9045b Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:26:25 -0700 Subject: [PATCH 03/12] unify server and client keepalive matching comments and discussion on first round of review from https://github.com/grpc/grpc-node/pull/2760 --- packages/grpc-js/src/server.ts | 284 ++++++++++++++++-------------- packages/grpc-js/src/transport.ts | 105 ++++++----- 2 files changed, 197 insertions(+), 192 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index aed65bbb0..ae3ae29ca 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -435,6 +435,14 @@ export class Server { ); } + private keepaliveTrace(text: string): void { + logging.trace( + LogVerbosity.DEBUG, + 'keepalive', + '(' + this.channelzRef.id + ') ' + text + ); + } + addProtoService(): never { throw new Error('Not implemented. Use addService() instead'); } @@ -1376,7 +1384,8 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; - let keepaliveInterval: NodeJS.Timeout | null = null; + let keepaliveTimeout: NodeJS.Timeout | null = null; + let keepaliveDisabled = false; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1419,72 +1428,73 @@ export class Server { connectionAgeTimer.unref?.(); } - if (this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS) { - keepaliveInterval = setInterval(() => { - const keepaliveTimeout = setTimeout(() => { - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; + const clearKeepaliveTimeout = () => { + if (keepaliveTimeout) { + clearTimeout(keepaliveTimeout); + keepaliveTimeout = null; + } + }; + + const canSendPing = () => { + return ( + !keepaliveDisabled && + this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS && + this.keepaliveTimeMs > 0 + ); + }; + + const maybeStartKeepalivePingTimer = () => { + if (!canSendPing()) { + return; + } + this.keepaliveTrace( + 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' + ); + keepaliveTimeout = setTimeout(() => { + clearKeepaliveTimeout(); + sendPing(); + }, this.keepaliveTimeMs); + keepaliveTimeout.unref?.(); + }; + + const sendPing = () => { + if (!canSendPing()) { + return; + } + this.keepaliveTrace( + 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' + ); + const pingSentSuccessfully = session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error: ' + err.message); sessionClosedByServer = true; - this.trace('Connection dropped by keepalive timeout'); session.close(); + } else { + this.keepaliveTrace('Received ping response'); + maybeStartKeepalivePingTimer(); } - }, this.keepaliveTimeoutMs); - keepaliveTimeout.unref?.(); - - try { - if ( - !session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - clearTimeout(keepaliveTimeout); - if (err) { - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } - sessionClosedByServer = true; - this.trace( - 'Connection dropped due to error with ping frame ' + - err.message + - ' return in ' + - duration - ); - session.close(); - } - } - ) - ) { - throw new Error('Server keepalive ping send failed'); - } - } catch (e) { - // The ping can't be sent because the session is already closed, max outstanding pings reached, etc - clearTimeout(keepaliveTimeout); - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } - this.trace( - 'Connection dropped due to error sending ping frame ' + - (e instanceof Error ? e.message : 'unknown error') - ); - session.destroy(); } - }, this.keepaliveTimeMs); - keepaliveInterval.unref?.(); - } + ); - session.once('goaway', (errorCode, lastStreamID, opaqueData) => { - if (errorCode === http2.constants.NGHTTP2_ENHANCE_YOUR_CALM) { - this.trace('Connection dropped by client due to ENHANCE_YOUR_CALM'); - } else { - this.trace( - 'Connection dropped by client via GOAWAY with error code ' + - errorCode - ); + if (!pingSentSuccessfully) { + this.keepaliveTrace('Ping failed to send'); + sessionClosedByServer = true; + session.close(); + return; } - sessionClosedByServer = true; - session.destroy(); - }); + + keepaliveTimeout = setTimeout(() => { + clearKeepaliveTimeout(); + this.keepaliveTrace('Ping timeout passed without response'); + sessionClosedByServer = true; + session.close(); + }, this.keepaliveTimeoutMs); + keepaliveTimeout.unref?.(); + }; + + maybeStartKeepalivePingTimer(); session.on('close', () => { if (!sessionClosedByServer) { @@ -1501,10 +1511,8 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } + keepaliveDisabled = true; + clearKeepaliveTimeout(); if (idleTimeoutObj !== null) { clearTimeout(idleTimeoutObj.timeout); @@ -1549,7 +1557,8 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; - let keepaliveInterval: NodeJS.Timeout | null = null; + let keepaliveTimeout: NodeJS.Timeout | null = null; + let keepaliveDisabled = false; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1591,85 +1600,90 @@ export class Server { connectionAgeTimer.unref?.(); } - if (this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS) { - keepaliveInterval = setInterval(() => { - const keepaliveTimeout = setTimeout(() => { - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - sessionClosedByServer = true; + const clearKeepaliveTimeout = () => { + if (keepaliveTimeout) { + clearTimeout(keepaliveTimeout); + keepaliveTimeout = null; + } + }; + + const canSendPing = () => { + return ( + !keepaliveDisabled && + this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS && + this.keepaliveTimeMs > 0 + ); + }; + + const maybeStartKeepalivePingTimer = () => { + if (!canSendPing()) { + return; + } + this.keepaliveTrace( + 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' + ); + keepaliveTimeout = setTimeout(() => { + clearKeepaliveTimeout(); + sendPing(); + }, this.keepaliveTimeMs); + keepaliveTimeout.unref?.(); + }; + + const sendPing = () => { + if (!canSendPing()) { + return; + } + this.keepaliveTrace( + 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' + ); + const pingSentSuccessfully = session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error: ' + err.message); this.channelzTrace.addTrace( 'CT_INFO', - 'Connection dropped by keepalive timeout from ' + clientAddress + 'Connection dropped due to error of a ping frame ' + + err.message + + ' return in ' + + duration ); + sessionClosedByServer = true; session.close(); + } else { + this.keepaliveTrace('Received ping response'); + maybeStartKeepalivePingTimer(); } - }, this.keepaliveTimeoutMs); - keepaliveTimeout.unref?.(); - - try { - if ( - !session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - clearTimeout(keepaliveTimeout); - if (err) { - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } - sessionClosedByServer = true; - this.channelzTrace.addTrace( - 'CT_INFO', - 'Connection dropped due to error with ping frame ' + - err.message + - ' return in ' + - duration - ); - session.close(); - } - } - ) - ) { - throw new Error('Server keepalive ping send failed'); - } - channelzSessionInfo.keepAlivesSent += 1; - } catch (e) { - // The ping can't be sent because the session is already closed, max outstanding pings reached, etc - clearTimeout(keepaliveTimeout); - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } - this.channelzTrace.addTrace( - 'CT_INFO', - 'Connection dropped due to error sending ping frame ' + - (e instanceof Error ? e.message : 'unknown error') - ); - session.destroy(); } - }, this.keepaliveTimeMs); - keepaliveInterval.unref?.(); - } + ); - session.once('goaway', (errorCode, lastStreamID, opaqueData) => { - if (errorCode === http2.constants.NGHTTP2_ENHANCE_YOUR_CALM) { + if (!pingSentSuccessfully) { + this.keepaliveTrace('Ping failed to send'); this.channelzTrace.addTrace( 'CT_INFO', - 'Connection dropped by client due GOAWAY of ENHANCE_YOUR_CALM from ' + - clientAddress + 'Connection dropped due failure to send ping frame' ); - } else { + sessionClosedByServer = true; + session.close(); + return; + } + + channelzSessionInfo.keepAlivesSent += 1; + + keepaliveTimeout = setTimeout(() => { + clearKeepaliveTimeout(); + this.keepaliveTrace('Ping timeout passed without response'); this.channelzTrace.addTrace( 'CT_INFO', - 'Connection dropped by client via GOAWAY with error code ' + - errorCode + - ' from ' + - clientAddress + 'Connection dropped by keepalive timeout from ' + clientAddress ); - } - sessionClosedByServer = true; - session.destroy(); - }); + sessionClosedByServer = true; + session.close(); + }, this.keepaliveTimeoutMs); + keepaliveTimeout.unref?.(); + }; + + maybeStartKeepalivePingTimer(); session.on('close', () => { if (!sessionClosedByServer) { @@ -1690,10 +1704,8 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - if (keepaliveInterval) { - clearInterval(keepaliveInterval); - keepaliveInterval = null; - } + keepaliveDisabled = true; + clearKeepaliveTimeout(); if (idleTimeoutObj !== null) { clearTimeout(idleTimeoutObj.timeout); diff --git a/packages/grpc-js/src/transport.ts b/packages/grpc-js/src/transport.ts index 71d0f26b3..b56cd5b85 100644 --- a/packages/grpc-js/src/transport.ts +++ b/packages/grpc-js/src/transport.ts @@ -101,28 +101,29 @@ class Http2Transport implements Transport { /** * The amount of time in between sending pings */ - private keepaliveTimeMs = -1; + private readonly keepaliveTimeMs: number; /** * The amount of time to wait for an acknowledgement after sending a ping */ - private keepaliveTimeoutMs: number = KEEPALIVE_TIMEOUT_MS; + private readonly keepaliveTimeoutMs: number; /** - * Timer reference for timeout that indicates when to send the next ping + * Indicates whether keepalive pings should be sent without any active calls + */ + private readonly keepaliveWithoutCalls: boolean; + /** + * Timer reference indicating when to send the next ping or when the most recent ping will be considered lost. */ - private keepaliveTimerId: NodeJS.Timeout | null = null; + private keepaliveTimeout: NodeJS.Timeout | null = null; /** * Indicates that the keepalive timer ran out while there were no active * calls, and a ping should be sent the next time a call starts. */ private pendingSendKeepalivePing = false; /** - * Timer reference tracking when the most recent ping will be considered lost + * Indicates when keepalives should no longer be performed for this transport. Used to prevent a race where a + * latent session.ping(..) callback is called after the transport has been notified to disconnect. */ - private keepaliveTimeoutId: NodeJS.Timeout | null = null; - /** - * Indicates whether keepalive pings should be sent without any active calls - */ - private keepaliveWithoutCalls = false; + private keepaliveDisabled = false; private userAgent: string; @@ -182,9 +183,13 @@ class Http2Transport implements Transport { if ('grpc.keepalive_time_ms' in options) { this.keepaliveTimeMs = options['grpc.keepalive_time_ms']!; + } else { + this.keepaliveTimeMs = -1; } if ('grpc.keepalive_timeout_ms' in options) { this.keepaliveTimeoutMs = options['grpc.keepalive_timeout_ms']!; + } else { + this.keepaliveTimeoutMs = KEEPALIVE_TIMEOUT_MS; } if ('grpc.keepalive_permit_without_calls' in options) { this.keepaliveWithoutCalls = @@ -195,7 +200,6 @@ class Http2Transport implements Transport { session.once('close', () => { this.trace('session closed'); - this.stopKeepalivePings(); this.handleDisconnect(); }); @@ -383,6 +387,8 @@ class Http2Transport implements Transport { * Handle connection drops, but not GOAWAYs. */ private handleDisconnect() { + this.keepaliveDisabled = true; + this.clearKeepaliveTimeout(); this.reportDisconnectToOwner(false); /* Give calls an event loop cycle to finish naturally before reporting the * disconnnection to them. */ @@ -397,63 +403,48 @@ class Http2Transport implements Transport { this.disconnectListeners.push(listener); } - private clearKeepaliveTimer() { - if (!this.keepaliveTimerId) { - return; - } - clearTimeout(this.keepaliveTimerId); - this.keepaliveTimerId = null; - } - - private clearKeepaliveTimeout() { - if (!this.keepaliveTimeoutId) { - return; - } - clearTimeout(this.keepaliveTimeoutId); - this.keepaliveTimeoutId = null; - } - private canSendPing() { return ( + !this.keepaliveDisabled && this.keepaliveTimeMs > 0 && (this.keepaliveWithoutCalls || this.activeCalls.size > 0) ); } private maybeSendPing() { - this.clearKeepaliveTimer(); if (!this.canSendPing()) { this.pendingSendKeepalivePing = true; return; } + if (this.keepaliveTimeout) { + console.error('keepaliveTimeout is not null'); + return; + } if (this.channelzEnabled) { this.keepalivesSent += 1; } this.keepaliveTrace( 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' ); - if (!this.keepaliveTimeoutId) { - this.keepaliveTimeoutId = setTimeout(() => { - this.keepaliveTrace('Ping timeout passed without response'); - this.handleDisconnect(); - }, this.keepaliveTimeoutMs); - this.keepaliveTimeoutId.unref?.(); - } - try { - this.session!.ping( - (err: Error | null, duration: number, payload: Buffer) => { - if (err) { - this.keepaliveTrace('Ping failed with error ' + err.message); - this.handleDisconnect(); - } + this.keepaliveTimeout = setTimeout(() => { + this.keepaliveTrace('Ping timeout passed without response'); + this.handleDisconnect(); + }, this.keepaliveTimeoutMs); + this.keepaliveTimeout.unref?.(); + const pingSentSuccessfully = this.session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + this.clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error ' + err.message); + this.handleDisconnect(); + } else { this.keepaliveTrace('Received ping response'); - this.clearKeepaliveTimeout(); this.maybeStartKeepalivePingTimer(); } - ); - } catch (e) { - /* If we fail to send a ping, the connection is no longer functional, so - * we should discard it. */ + } + ); + if (!pingSentSuccessfully) { + this.keepaliveTrace('Ping failed to send'); this.handleDisconnect(); } } @@ -471,25 +462,27 @@ class Http2Transport implements Transport { if (this.pendingSendKeepalivePing) { this.pendingSendKeepalivePing = false; this.maybeSendPing(); - } else if (!this.keepaliveTimerId && !this.keepaliveTimeoutId) { + } else if (!this.keepaliveTimeout) { this.keepaliveTrace( 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' ); - this.keepaliveTimerId = setTimeout(() => { + this.keepaliveTimeout = setTimeout(() => { this.maybeSendPing(); }, this.keepaliveTimeMs); - this.keepaliveTimerId.unref?.(); + this.keepaliveTimeout.unref?.(); } /* Otherwise, there is already either a keepalive timer or a ping pending, * wait for those to resolve. */ } - private stopKeepalivePings() { - if (this.keepaliveTimerId) { - clearTimeout(this.keepaliveTimerId); - this.keepaliveTimerId = null; + /** + * Clears whichever keepalive timeout is currently active, if any. + */ + private clearKeepaliveTimeout() { + if (this.keepaliveTimeout) { + clearTimeout(this.keepaliveTimeout); + this.keepaliveTimeout = null; } - this.clearKeepaliveTimeout(); } private removeActiveCall(call: Http2SubchannelCall) { @@ -533,7 +526,7 @@ class Http2Transport implements Transport { * error here. */ try { - http2Stream = this.session!.request(headers); + http2Stream = this.session.request(headers); } catch (e) { this.handleDisconnect(); throw e; From 577b4b4748fbd12e2576e465d837f1ae320a096f Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:32:09 -0700 Subject: [PATCH 04/12] add keepalive server trace back in to match channelz vs non-channelz trace behavior --- packages/grpc-js/src/server.ts | 77 ++++++++++++++++++---------------- 1 file changed, 42 insertions(+), 35 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index ae3ae29ca..88846eaf5 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -18,43 +18,67 @@ import * as http2 from 'http2'; import * as util from 'util'; +import { CipherNameAndProtocol, TLSSocket } from 'tls'; import { ServiceError } from './call'; -import { Status, LogVerbosity } from './constants'; +import { PartialStatusObject } from './call-interface'; +import { ChannelOptions } from './channel-options'; +import { + ChannelzCallTracker, + ChannelzCallTrackerStub, + ChannelzChildrenTracker, + ChannelzChildrenTrackerStub, + ChannelzTrace, + ChannelzTraceStub, + ServerInfo, + ServerRef, + SocketInfo, + SocketRef, + TlsInfo, + registerChannelzServer, + registerChannelzSocket, + unregisterChannelzRef, +} from './channelz'; +import { LogVerbosity, Status } from './constants'; +import * as logging from './logging'; import { Deserialize, Serialize, ServiceDefinition } from './make-client'; import { Metadata } from './metadata'; +import { + ResolverListener, + createResolver, + mapUriDefaultScheme, +} from './resolver'; import { BidiStreamingHandler, ClientStreamingHandler, HandleCall, Handler, HandlerType, - sendUnaryData, ServerDuplexStream, ServerDuplexStreamImpl, + ServerErrorResponse, ServerReadableStream, + ServerStatusResponse, ServerStreamingHandler, ServerUnaryCall, ServerWritableStream, ServerWritableStreamImpl, UnaryHandler, - ServerErrorResponse, - ServerStatusResponse, + sendUnaryData, serverErrorToStatus, } from './server-call'; import { ServerCredentials } from './server-credentials'; -import { ChannelOptions } from './channel-options'; import { - createResolver, - ResolverListener, - mapUriDefaultScheme, -} from './resolver'; -import * as logging from './logging'; + ServerInterceptingCallInterface, + ServerInterceptor, + getServerInterceptingCall, +} from './server-interceptors'; import { SubchannelAddress, isTcpSubchannelAddress, - subchannelAddressToString, stringToSubchannelAddress, + subchannelAddressToString, } from './subchannel-address'; +import { CallEventTracker } from './transport'; import { GrpcUri, combineHostPort, @@ -62,30 +86,6 @@ import { splitHostPort, uriToString, } from './uri-parser'; -import { - ChannelzCallTracker, - ChannelzCallTrackerStub, - ChannelzChildrenTracker, - ChannelzChildrenTrackerStub, - ChannelzTrace, - ChannelzTraceStub, - registerChannelzServer, - registerChannelzSocket, - ServerInfo, - ServerRef, - SocketInfo, - SocketRef, - TlsInfo, - unregisterChannelzRef, -} from './channelz'; -import { CipherNameAndProtocol, TLSSocket } from 'tls'; -import { - ServerInterceptingCallInterface, - ServerInterceptor, - getServerInterceptingCall, -} from './server-interceptors'; -import { PartialStatusObject } from './call-interface'; -import { CallEventTracker } from './transport'; const UNLIMITED_CONNECTION_AGE_MS = ~(1 << 31); const KEEPALIVE_MAX_TIME_MS = ~(1 << 31); @@ -1469,6 +1469,12 @@ export class Server { clearKeepaliveTimeout(); if (err) { this.keepaliveTrace('Ping failed with error: ' + err.message); + this.trace( + 'Connection dropped due to error of a ping frame ' + + err.message + + ' return in ' + + duration + ); sessionClosedByServer = true; session.close(); } else { @@ -1480,6 +1486,7 @@ export class Server { if (!pingSentSuccessfully) { this.keepaliveTrace('Ping failed to send'); + this.trace('Connection dropped due to failure to send ping frame'); sessionClosedByServer = true; session.close(); return; From 7883164137c4994af074201818a81108bda8204a Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:35:40 -0700 Subject: [PATCH 05/12] return imports back to original order --- packages/grpc-js/src/server.ts | 70 +++++++++++++++++----------------- 1 file changed, 35 insertions(+), 35 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index 88846eaf5..ad463b957 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -18,67 +18,43 @@ import * as http2 from 'http2'; import * as util from 'util'; -import { CipherNameAndProtocol, TLSSocket } from 'tls'; import { ServiceError } from './call'; -import { PartialStatusObject } from './call-interface'; -import { ChannelOptions } from './channel-options'; -import { - ChannelzCallTracker, - ChannelzCallTrackerStub, - ChannelzChildrenTracker, - ChannelzChildrenTrackerStub, - ChannelzTrace, - ChannelzTraceStub, - ServerInfo, - ServerRef, - SocketInfo, - SocketRef, - TlsInfo, - registerChannelzServer, - registerChannelzSocket, - unregisterChannelzRef, -} from './channelz'; -import { LogVerbosity, Status } from './constants'; -import * as logging from './logging'; +import { Status, LogVerbosity } from './constants'; import { Deserialize, Serialize, ServiceDefinition } from './make-client'; import { Metadata } from './metadata'; -import { - ResolverListener, - createResolver, - mapUriDefaultScheme, -} from './resolver'; import { BidiStreamingHandler, ClientStreamingHandler, HandleCall, Handler, HandlerType, + sendUnaryData, ServerDuplexStream, ServerDuplexStreamImpl, - ServerErrorResponse, ServerReadableStream, - ServerStatusResponse, ServerStreamingHandler, ServerUnaryCall, ServerWritableStream, ServerWritableStreamImpl, UnaryHandler, - sendUnaryData, + ServerErrorResponse, + ServerStatusResponse, serverErrorToStatus, } from './server-call'; import { ServerCredentials } from './server-credentials'; +import { ChannelOptions } from './channel-options'; import { - ServerInterceptingCallInterface, - ServerInterceptor, - getServerInterceptingCall, -} from './server-interceptors'; + createResolver, + ResolverListener, + mapUriDefaultScheme, +} from './resolver'; +import * as logging from './logging'; import { SubchannelAddress, isTcpSubchannelAddress, - stringToSubchannelAddress, subchannelAddressToString, + stringToSubchannelAddress, } from './subchannel-address'; -import { CallEventTracker } from './transport'; import { GrpcUri, combineHostPort, @@ -86,6 +62,30 @@ import { splitHostPort, uriToString, } from './uri-parser'; +import { + ChannelzCallTracker, + ChannelzCallTrackerStub, + ChannelzChildrenTracker, + ChannelzChildrenTrackerStub, + ChannelzTrace, + ChannelzTraceStub, + registerChannelzServer, + registerChannelzSocket, + ServerInfo, + ServerRef, + SocketInfo, + SocketRef, + TlsInfo, + unregisterChannelzRef, +} from './channelz'; +import { CipherNameAndProtocol, TLSSocket } from 'tls'; +import { + ServerInterceptingCallInterface, + ServerInterceptor, + getServerInterceptingCall, +} from './server-interceptors'; +import { PartialStatusObject } from './call-interface'; +import { CallEventTracker } from './transport'; const UNLIMITED_CONNECTION_AGE_MS = ~(1 << 31); const KEEPALIVE_MAX_TIME_MS = ~(1 << 31); From 19cdc1233c40b4586d29fc6454e95152af4661f6 Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:37:24 -0700 Subject: [PATCH 06/12] another missing trace message for parity --- packages/grpc-js/src/server.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index ad463b957..9ed9b8d7e 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1495,6 +1495,7 @@ export class Server { keepaliveTimeout = setTimeout(() => { clearKeepaliveTimeout(); this.keepaliveTrace('Ping timeout passed without response'); + this.trace('Connection dropped by keepalive timeout'); sessionClosedByServer = true; session.close(); }, this.keepaliveTimeoutMs); From bed5e85af9b5214c5827d9cb7c1465a8ee57ee7c Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:43:51 -0700 Subject: [PATCH 07/12] resolve hoisting --- packages/grpc-js/src/server.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index 9ed9b8d7e..2dc3c2f3d 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1623,6 +1623,9 @@ export class Server { ); }; + /* eslint-disable-next-line prefer-const */ + let sendPing: () => void; // hoisted for use in maybeStartKeepalivePingTimer + const maybeStartKeepalivePingTimer = () => { if (!canSendPing()) { return; @@ -1637,7 +1640,7 @@ export class Server { keepaliveTimeout.unref?.(); }; - const sendPing = () => { + sendPing = () => { if (!canSendPing()) { return; } From d325b5fff38a240cb3b43a70e0c7ce326c1f692e Mon Sep 17 00:00:00 2001 From: David Fiala Date: Tue, 28 May 2024 22:46:48 -0700 Subject: [PATCH 08/12] hoist in second location --- packages/grpc-js/src/server.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index 2dc3c2f3d..b749740d4 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1443,6 +1443,9 @@ export class Server { ); }; + /* eslint-disable-next-line prefer-const */ + let sendPing: () => void; // hoisted for use in maybeStartKeepalivePingTimer + const maybeStartKeepalivePingTimer = () => { if (!canSendPing()) { return; @@ -1457,7 +1460,7 @@ export class Server { keepaliveTimeout.unref?.(); }; - const sendPing = () => { + sendPing = () => { if (!canSendPing()) { return; } From a77d94f7c62045253343349d6b140795b8db73a4 Mon Sep 17 00:00:00 2001 From: David Fiala Date: Wed, 29 May 2024 10:37:40 -0700 Subject: [PATCH 09/12] Based on grpc/grpc-node#2139 I wrapped http2session.ping in a try-catch block again --- packages/grpc-js/src/server.ts | 98 ++++++++++++++++++------------- packages/grpc-js/src/transport.ts | 33 +++++++---- 2 files changed, 78 insertions(+), 53 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index b749740d4..8db0aac5a 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1467,29 +1467,35 @@ export class Server { this.keepaliveTrace( 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' ); - const pingSentSuccessfully = session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - clearKeepaliveTimeout(); - if (err) { - this.keepaliveTrace('Ping failed with error: ' + err.message); - this.trace( - 'Connection dropped due to error of a ping frame ' + - err.message + - ' return in ' + - duration - ); - sessionClosedByServer = true; - session.close(); - } else { - this.keepaliveTrace('Received ping response'); - maybeStartKeepalivePingTimer(); + let pingSendError = ''; + try { + const pingSentSuccessfully = session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error: ' + err.message); + sessionClosedByServer = true; + session.close(); + } else { + this.keepaliveTrace('Received ping response'); + maybeStartKeepalivePingTimer(); + } } + ); + if (!pingSentSuccessfully) { + pingSendError = 'Ping returned false'; } - ); + } catch (e) { + // grpc/grpc-node#2139 + pingSendError = + (e instanceof Error ? e.message : '') || 'Unknown error'; + } - if (!pingSentSuccessfully) { - this.keepaliveTrace('Ping failed to send'); - this.trace('Connection dropped due to failure to send ping frame'); + if (pingSendError) { + this.keepaliveTrace('Ping send failed: ' + pingSendError); + this.trace( + 'Connection dropped due to ping send error: ' + pingSendError + ); sessionClosedByServer = true; session.close(); return; @@ -1650,32 +1656,42 @@ export class Server { this.keepaliveTrace( 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' ); - const pingSentSuccessfully = session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - clearKeepaliveTimeout(); - if (err) { - this.keepaliveTrace('Ping failed with error: ' + err.message); - this.channelzTrace.addTrace( - 'CT_INFO', - 'Connection dropped due to error of a ping frame ' + - err.message + - ' return in ' + - duration - ); - sessionClosedByServer = true; - session.close(); - } else { - this.keepaliveTrace('Received ping response'); - maybeStartKeepalivePingTimer(); + let pingSendError = ''; + try { + const pingSentSuccessfully = session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error: ' + err.message); + this.channelzTrace.addTrace( + 'CT_INFO', + 'Connection dropped due to error of a ping frame ' + + err.message + + ' return in ' + + duration + ); + sessionClosedByServer = true; + session.close(); + } else { + this.keepaliveTrace('Received ping response'); + maybeStartKeepalivePingTimer(); + } } + ); + if (!pingSentSuccessfully) { + pingSendError = 'Ping returned false'; } - ); + } catch (e) { + // grpc/grpc-node#2139 + pingSendError = + (e instanceof Error ? e.message : '') || 'Unknown error'; + } - if (!pingSentSuccessfully) { - this.keepaliveTrace('Ping failed to send'); + if (pingSendError) { + this.keepaliveTrace('Ping send failed: ' + pingSendError); this.channelzTrace.addTrace( 'CT_INFO', - 'Connection dropped due failure to send ping frame' + 'Connection dropped due to ping send error: ' + pingSendError ); sessionClosedByServer = true; session.close(); diff --git a/packages/grpc-js/src/transport.ts b/packages/grpc-js/src/transport.ts index b56cd5b85..a3f5a78f5 100644 --- a/packages/grpc-js/src/transport.ts +++ b/packages/grpc-js/src/transport.ts @@ -431,20 +431,29 @@ class Http2Transport implements Transport { this.handleDisconnect(); }, this.keepaliveTimeoutMs); this.keepaliveTimeout.unref?.(); - const pingSentSuccessfully = this.session.ping( - (err: Error | null, duration: number, payload: Buffer) => { - this.clearKeepaliveTimeout(); - if (err) { - this.keepaliveTrace('Ping failed with error ' + err.message); - this.handleDisconnect(); - } else { - this.keepaliveTrace('Received ping response'); - this.maybeStartKeepalivePingTimer(); + let pingSendError = ''; + try { + const pingSentSuccessfully = this.session.ping( + (err: Error | null, duration: number, payload: Buffer) => { + this.clearKeepaliveTimeout(); + if (err) { + this.keepaliveTrace('Ping failed with error ' + err.message); + this.handleDisconnect(); + } else { + this.keepaliveTrace('Received ping response'); + this.maybeStartKeepalivePingTimer(); + } } + ); + if (!pingSentSuccessfully) { + pingSendError = 'Ping returned false'; } - ); - if (!pingSentSuccessfully) { - this.keepaliveTrace('Ping failed to send'); + } catch (e) { + // grpc/grpc-node#2139 + pingSendError = (e instanceof Error ? e.message : '') || 'Unknown error'; + } + if (pingSendError) { + this.keepaliveTrace('Ping send failed: ' + pingSendError); this.handleDisconnect(); } } From c2da436a8e089c9168c8a430347819442e86ac6a Mon Sep 17 00:00:00 2001 From: David Fiala Date: Wed, 29 May 2024 15:09:55 -0700 Subject: [PATCH 10/12] remove keepaliveDisabled from server.ts. rename keepaliveTimer. --- packages/grpc-js/src/server.ts | 24 ++++++++++-------------- packages/grpc-js/src/transport.ts | 20 ++++++++++---------- 2 files changed, 20 insertions(+), 24 deletions(-) diff --git a/packages/grpc-js/src/server.ts b/packages/grpc-js/src/server.ts index 8db0aac5a..33db41004 100644 --- a/packages/grpc-js/src/server.ts +++ b/packages/grpc-js/src/server.ts @@ -1384,8 +1384,7 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; - let keepaliveTimeout: NodeJS.Timeout | null = null; - let keepaliveDisabled = false; + let keepaliveTimer: NodeJS.Timeout | null = null; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1429,15 +1428,15 @@ export class Server { } const clearKeepaliveTimeout = () => { - if (keepaliveTimeout) { - clearTimeout(keepaliveTimeout); - keepaliveTimeout = null; + if (keepaliveTimer) { + clearTimeout(keepaliveTimer); + keepaliveTimer = null; } }; const canSendPing = () => { return ( - !keepaliveDisabled && + !session.destroyed && this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS && this.keepaliveTimeMs > 0 ); @@ -1453,11 +1452,11 @@ export class Server { this.keepaliveTrace( 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' ); - keepaliveTimeout = setTimeout(() => { + keepaliveTimer = setTimeout(() => { clearKeepaliveTimeout(); sendPing(); }, this.keepaliveTimeMs); - keepaliveTimeout.unref?.(); + keepaliveTimer.unref?.(); }; sendPing = () => { @@ -1501,14 +1500,14 @@ export class Server { return; } - keepaliveTimeout = setTimeout(() => { + keepaliveTimer = setTimeout(() => { clearKeepaliveTimeout(); this.keepaliveTrace('Ping timeout passed without response'); this.trace('Connection dropped by keepalive timeout'); sessionClosedByServer = true; session.close(); }, this.keepaliveTimeoutMs); - keepaliveTimeout.unref?.(); + keepaliveTimer.unref?.(); }; maybeStartKeepalivePingTimer(); @@ -1528,7 +1527,6 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - keepaliveDisabled = true; clearKeepaliveTimeout(); if (idleTimeoutObj !== null) { @@ -1575,7 +1573,6 @@ export class Server { let connectionAgeTimer: NodeJS.Timeout | null = null; let connectionAgeGraceTimer: NodeJS.Timeout | null = null; let keepaliveTimeout: NodeJS.Timeout | null = null; - let keepaliveDisabled = false; let sessionClosedByServer = false; const idleTimeoutObj = this.enableIdleTimeout(session); @@ -1626,7 +1623,7 @@ export class Server { const canSendPing = () => { return ( - !keepaliveDisabled && + !session.destroyed && this.keepaliveTimeMs < KEEPALIVE_MAX_TIME_MS && this.keepaliveTimeMs > 0 ); @@ -1734,7 +1731,6 @@ export class Server { clearTimeout(connectionAgeGraceTimer); } - keepaliveDisabled = true; clearKeepaliveTimeout(); if (idleTimeoutObj !== null) { diff --git a/packages/grpc-js/src/transport.ts b/packages/grpc-js/src/transport.ts index a3f5a78f5..b7ac2df7b 100644 --- a/packages/grpc-js/src/transport.ts +++ b/packages/grpc-js/src/transport.ts @@ -113,7 +113,7 @@ class Http2Transport implements Transport { /** * Timer reference indicating when to send the next ping or when the most recent ping will be considered lost. */ - private keepaliveTimeout: NodeJS.Timeout | null = null; + private keepaliveTimer: NodeJS.Timeout | null = null; /** * Indicates that the keepalive timer ran out while there were no active * calls, and a ping should be sent the next time a call starts. @@ -416,7 +416,7 @@ class Http2Transport implements Transport { this.pendingSendKeepalivePing = true; return; } - if (this.keepaliveTimeout) { + if (this.keepaliveTimer) { console.error('keepaliveTimeout is not null'); return; } @@ -426,11 +426,11 @@ class Http2Transport implements Transport { this.keepaliveTrace( 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' ); - this.keepaliveTimeout = setTimeout(() => { + this.keepaliveTimer = setTimeout(() => { this.keepaliveTrace('Ping timeout passed without response'); this.handleDisconnect(); }, this.keepaliveTimeoutMs); - this.keepaliveTimeout.unref?.(); + this.keepaliveTimer.unref?.(); let pingSendError = ''; try { const pingSentSuccessfully = this.session.ping( @@ -471,14 +471,14 @@ class Http2Transport implements Transport { if (this.pendingSendKeepalivePing) { this.pendingSendKeepalivePing = false; this.maybeSendPing(); - } else if (!this.keepaliveTimeout) { + } else if (!this.keepaliveTimer) { this.keepaliveTrace( 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' ); - this.keepaliveTimeout = setTimeout(() => { + this.keepaliveTimer = setTimeout(() => { this.maybeSendPing(); }, this.keepaliveTimeMs); - this.keepaliveTimeout.unref?.(); + this.keepaliveTimer.unref?.(); } /* Otherwise, there is already either a keepalive timer or a ping pending, * wait for those to resolve. */ @@ -488,9 +488,9 @@ class Http2Transport implements Transport { * Clears whichever keepalive timeout is currently active, if any. */ private clearKeepaliveTimeout() { - if (this.keepaliveTimeout) { - clearTimeout(this.keepaliveTimeout); - this.keepaliveTimeout = null; + if (this.keepaliveTimer) { + clearTimeout(this.keepaliveTimer); + this.keepaliveTimer = null; } } From 3c5ab229b1838f624ace174eef850f7cb611df9e Mon Sep 17 00:00:00 2001 From: David Fiala Date: Wed, 5 Jun 2024 19:01:02 -0700 Subject: [PATCH 11/12] per discussion, avoid tracking keepalive disabled state and instead depend on whether the session is destroyed --- packages/grpc-js/src/transport.ts | 9 ++------- 1 file changed, 2 insertions(+), 7 deletions(-) diff --git a/packages/grpc-js/src/transport.ts b/packages/grpc-js/src/transport.ts index b7ac2df7b..ab5438211 100644 --- a/packages/grpc-js/src/transport.ts +++ b/packages/grpc-js/src/transport.ts @@ -119,11 +119,6 @@ class Http2Transport implements Transport { * calls, and a ping should be sent the next time a call starts. */ private pendingSendKeepalivePing = false; - /** - * Indicates when keepalives should no longer be performed for this transport. Used to prevent a race where a - * latent session.ping(..) callback is called after the transport has been notified to disconnect. - */ - private keepaliveDisabled = false; private userAgent: string; @@ -387,7 +382,6 @@ class Http2Transport implements Transport { * Handle connection drops, but not GOAWAYs. */ private handleDisconnect() { - this.keepaliveDisabled = true; this.clearKeepaliveTimeout(); this.reportDisconnectToOwner(false); /* Give calls an event loop cycle to finish naturally before reporting the @@ -396,6 +390,7 @@ class Http2Transport implements Transport { for (const call of this.activeCalls) { call.onDisconnect(); } + this.session.destroy(); }); } @@ -405,7 +400,7 @@ class Http2Transport implements Transport { private canSendPing() { return ( - !this.keepaliveDisabled && + !this.session.destroyed && this.keepaliveTimeMs > 0 && (this.keepaliveWithoutCalls || this.activeCalls.size > 0) ); From 98cd87f7512c95cd48bf04c3225f0fa22b5dcb78 Mon Sep 17 00:00:00 2001 From: David Fiala Date: Thu, 6 Jun 2024 22:57:13 -0700 Subject: [PATCH 12/12] ensure that client keepalive timers are always cleared when they trigger. this is a necessary change to fit with having removed keepaliveDisabled boolean. manually inspected test logs for both server.ts and transport.ts to verify both types of keepalives are operating correctly. --- packages/grpc-js/src/transport.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/packages/grpc-js/src/transport.ts b/packages/grpc-js/src/transport.ts index ab5438211..06509cb18 100644 --- a/packages/grpc-js/src/transport.ts +++ b/packages/grpc-js/src/transport.ts @@ -422,6 +422,7 @@ class Http2Transport implements Transport { 'Sending ping with timeout ' + this.keepaliveTimeoutMs + 'ms' ); this.keepaliveTimer = setTimeout(() => { + this.keepaliveTimer = null; this.keepaliveTrace('Ping timeout passed without response'); this.handleDisconnect(); }, this.keepaliveTimeoutMs); @@ -471,6 +472,7 @@ class Http2Transport implements Transport { 'Starting keepalive timer for ' + this.keepaliveTimeMs + 'ms' ); this.keepaliveTimer = setTimeout(() => { + this.keepaliveTimer = null; this.maybeSendPing(); }, this.keepaliveTimeMs); this.keepaliveTimer.unref?.();