HTTP/2 flow control tracing

subchannel_flowctrl tracer, if enabled, logs local and remote window sizes of subchannel's HTTP2 session to debug log every 5 seconds.
grpc · Feb 9, 2022 · c0052a1 · c0052a1
1 parent faa79fe
commit c0052a1
Show file tree

Hide file tree

Showing 2 changed files with 19 additions and 0 deletions.
diff --git a/doc/environment_variables.md b/doc/environment_variables.md
@@ -37,6 +37,7 @@ can be set.
   - `server_call` - Traces server handling of individual requests
   - `subchannel` - Traces subchannel connectivity state and errors
   - `subchannel_refcount` - Traces subchannel refcount changes
+  - `subchannel_flowctrl` - Traces HTTP/2 flow control
 
   The following tracers are added by the `@grpc/grpc-js-xds` library:
   - `cds_balancer` - Traces the CDS load balancing policy

diff --git a/packages/grpc-js/src/subchannel.ts b/packages/grpc-js/src/subchannel.ts
@@ -41,6 +41,7 @@ import { SubchannelRef, ChannelzTrace, ChannelzChildrenTracker, SubchannelInfo,
 const clientVersion = require('../../package.json').version;
 
 const TRACER_NAME = 'subchannel';
+const FLOW_CONTROL_TRACER_NAME = 'subchannel_flowctrl';
 
 const MIN_CONNECT_TIMEOUT_MS = 20000;
 const INITIAL_BACKOFF_MS = 1000;
@@ -176,6 +177,7 @@ export class Subchannel {
   private messagesReceived = 0;
   private lastMessageSentTimestamp: Date | null = null;
   private lastMessageReceivedTimestamp: Date | null = null;
+  private windowReportInterval: NodeJS.Timer | null = null;
 
   /**
    * A class representing a connection to a single backend.
@@ -324,6 +326,10 @@ export class Subchannel {
     logging.trace(LogVerbosity.DEBUG, 'subchannel_refcount', '(' + this.channelzRef.id + ') ' + this.subchannelAddressString + ' ' + text);
   }
 
+  private flowControlTrace(text: string): void {
+    logging.trace(LogVerbosity.DEBUG, FLOW_CONTROL_TRACER_NAME, '(' + this.channelzRef.id + ') ' + this.subchannelAddressString + ' ' + text);
+  }
+
   private handleBackoffTimer() {
     if (this.continueConnecting) {
       this.transitionToState(
@@ -573,6 +579,18 @@ export class Subchannel {
         );
       });
     }
+    if (logging.isTracerEnabled(FLOW_CONTROL_TRACER_NAME)) {
+      this.windowReportInterval = setInterval(() => {
+        if (!this.session) {
+          if (this.windowReportInterval) {
+            clearInterval(this.windowReportInterval);
+          }
+          return;
+        }
+        this.flowControlTrace('local window size: ' + this.session.state.localWindowSize);
+        this.flowControlTrace('remote window size: ' + this.session.state.remoteWindowSize);
+      }, 5000);
+    }
   }
 
   private startConnectingInternal() {