From 665632f48034f383b09704d82ec593624f4c0c20 Mon Sep 17 00:00:00 2001
From: Michael Lumish <mlumish@google.com>
Date: Thu, 27 Aug 2020 12:47:53 -0700
Subject: [PATCH] Add more keepalive logging

---
 packages/grpc-js/src/subchannel.ts | 13 +++++++------
 1 file changed, 7 insertions(+), 6 deletions(-)

diff --git a/packages/grpc-js/src/subchannel.ts b/packages/grpc-js/src/subchannel.ts
index 736562a6..c90df85e 100644
--- a/packages/grpc-js/src/subchannel.ts
+++ b/packages/grpc-js/src/subchannel.ts
@@ -28,7 +28,7 @@ import * as logging from './logging';
 import { LogVerbosity } from './constants';
 import { getProxiedConnection, ProxyConnectionResult } from './http_proxy';
 import * as net from 'net';
-import { GrpcUri, parseUri, splitHostPort } from './uri-parser';
+import { GrpcUri, parseUri, splitHostPort, uriToString } from './uri-parser';
 import { ConnectionOptions } from 'tls';
 import { FilterFactory, Filter } from './filter';
 
@@ -263,6 +263,7 @@ export class Subchannel {
   }
 
   private sendPing() {
+    logging.trace(LogVerbosity.DEBUG, 'keepalive', 'Sending ping to ' + this.subchannelAddressString);
     this.keepaliveTimeoutId = setTimeout(() => {
       this.transitionToState([ConnectivityState.READY], ConnectivityState.IDLE);
     }, this.keepaliveTimeoutMs);
@@ -405,14 +406,14 @@ export class Subchannel {
             errorCode === http2.constants.NGHTTP2_ENHANCE_YOUR_CALM &&
             opaqueData.equals(tooManyPingsData)
           ) {
-            logging.log(
-              LogVerbosity.ERROR,
-              `Connection to ${this.channelTarget} rejected by server because of excess pings`
-            );
             this.keepaliveTimeMs = Math.min(
               2 * this.keepaliveTimeMs,
               KEEPALIVE_MAX_TIME_MS
             );
+            logging.log(
+              LogVerbosity.ERROR,
+              `Connection to ${uriToString(this.channelTarget)} at ${this.subchannelAddressString} rejected by server because of excess pings. Increasing ping interval to ${this.keepaliveTimeMs}`
+            );
           }
           trace(
             this.subchannelAddressString +
@@ -689,7 +690,7 @@ export class Subchannel {
     for (const header of Object.keys(headers)) {
       headersString += '\t\t' + header + ': ' + headers[header] + '\n';
     }
-    trace('Starting stream with headers\n' + headersString);
+    logging.trace(LogVerbosity.DEBUG, 'call_stream', 'Starting stream on subchannel ' + this.subchannelAddressString + ' with headers\n' + headersString);
     callStream.attachHttp2Stream(http2Stream, this, extraFilterFactory);
   }