fix: separate T-Bank RPC network time from queue wait (WealthLedger/backend#81)

src/common/logging/structured-logger.service.ts

@@ -18,6 +18,7 @@ const allowedFields = new Set([
   'grpcCode',
   'headersReceived',
   'method',
+  'networkMs',
   'operation',
   'queueWaitMs',
   'requestId',

src/integrations/tbank/tbank.client.spec.ts

@@ -165,6 +165,8 @@ describe('TbankClient operations', () => {
         operation: 'getAccounts', grpcCode: status.DEADLINE_EXCEEDED,
         queueWaitMs: 0, channelState: 'CONNECTING', headersReceived: false,
       }));
+      const [, , fields] = logger.event.mock.calls.at(-1) as [string, string, { networkMs: unknown }];
+      expect(typeof fields.networkMs).toBe('number');
       expect(JSON.stringify(logger.event.mock.calls)).not.toContain('secret');
     } finally {
       jest.useRealTimers();

src/integrations/tbank/tbank.client.ts

@@ -64,6 +64,7 @@ type TbankClientService = Client & Record<string, Unary<never, never>>;
 type RpcDiagnostics = {
   channelState?: string;
   headersReceived?: boolean;
+  networkMs?: number;
   queueWaitMs?: number;
   trackingId?: string;
 };
@@ -524,10 +525,13 @@ export class TbankClient {
           throw new ServiceUnavailableException({ code: TbankErrorCode.Unavailable });
         }
         const response = await this.queue.run(() => {
-          diagnostics.queueWaitMs = Math.round(performance.now() - startedAt);
+          const sentAt = performance.now();
+          diagnostics.queueWaitMs = Math.round(sentAt - startedAt);
           return this.request<Response>(
             token, client, method, request, diagnostics,
-          );
+          ).finally(() => {
+            diagnostics.networkMs = Math.round(performance.now() - sentAt);
+          });
         });
         this.logger.event('debug', 'tbank.rpc.completed', {
           operation: method,