Merge pull request #2315 from metriport/1667-improve-retries-logging-…

…ihe-v2

Sub request id + improve retries logging for ihe v2 + Retries for ERR_BAD_RESPONSE on DQ

packages/api/src/external/carequality/document/create-outbound-document-retrieval-req.ts

@@ -1,3 +1,4 @@
+import { nanoid } from "nanoid";
 import { Patient } from "@metriport/core/domain/patient";
 import { capture } from "@metriport/core/util/notifications";
 import {
@@ -72,6 +73,7 @@ export function createOutboundDocumentRetrievalReqs({
  const request: OutboundDocumentRetrievalReq[] = docRefChunks.map(chunk => {
  return {
  ...baseRequest,
+ requestChunkId: nanoid(),
  documentReference: chunk,
  };
  });

packages/core/src/external/carequality/ihe-gateway-v2/ihe-gateway-v2-logic.ts

@@ -58,7 +58,7 @@ export async function sendProcessXcpdRequest({
  initialDelay: 3000,
  maxAttempts: 3,
  shouldRetry: isRetryableXcpd,
- log: out("sendProcessXcpdRequest").log,
+ log: out(`sendProcessRetryXcpdRequest, oid: ${signedRequest.gateway.oid}`).log,
  });
 }
 
@@ -92,7 +92,7 @@ export async function sendProcessRetryDqRequest({
  initialDelay: 3000,
  maxAttempts: 3,
  shouldRetry: isRetryableXca,
- log: out("sendProcessRetryDqRequest").log,
+ log: out(`sendProcessRetryDqRequest, oid: ${signedRequest.gateway.homeCommunityId}`).log,
  });
 }
 
@@ -121,12 +121,13 @@ export async function sendProcessRetryDrRequest({
  response,
  });
  }
-
  return await executeWithRetries(sendProcessDrRequest, {
  initialDelay: 3000,
  maxAttempts: 3,
  shouldRetry: isRetryableXca,
- log: out("sendProcessRetryDrRequest").log,
+ log: out(
+ `sendProcessRetryDrRequest, oid: ${signedRequest.outboundRequest.gateway.homeCommunityId}, requestChunkId: ${signedRequest.outboundRequest.requestChunkId}`
+ ).log,
  });
 }
 

packages/core/src/external/carequality/ihe-gateway-v2/monitor/__tests__/store.test.ts

@@ -23,15 +23,14 @@ it("should construct the correct file path for type 'dr' with index", async () =
  const requestId = "requestId";
  const oid = "oid";
  const timestamp = "2024-05-01T00:00:00";
- const index = 1;
  const key = buildIheResponseKey({
  type: "dr",
  cxId,
  patientId,
  requestId,
  oid,
  timestamp,
- index,
+ requestChunkId: "requestChunkId",
  });
- expect(key).toEqual(`${cxId}/${patientId}/dr/${requestId}_2024-05-01/${oid}_1.xml`);
+ expect(key).toEqual(`${cxId}/${patientId}/dr/${requestId}_2024-05-01/${oid}_requestChunkId.xml`);
 });

packages/core/src/external/carequality/ihe-gateway-v2/monitor/store.ts

@@ -94,12 +94,12 @@ export async function storeDrResponse({
  response,
  outboundRequest,
  gateway,
- index,
+ requestChunkId,
 }: {
  response: Buffer;
  outboundRequest: OutboundDocumentRetrievalReq;
  gateway: XCAGateway;
- index: number;
+ requestChunkId?: string | undefined;
 }) {
  try {
  if (!bucket) {
@@ -114,7 +114,7 @@ export async function storeDrResponse({
  requestId,
  oid: gateway.homeCommunityId,
  timestamp,
- index,
+ requestChunkId,
  });
  await s3Utils.uploadFile({ bucket, key, file: response, contentType: "application/xml" });
  } catch (error) {
@@ -129,17 +129,17 @@ export function buildIheResponseKey({
  requestId,
  oid,
  timestamp,
- index,
+ requestChunkId,
 }: {
  type: "xcpd" | "dq" | "dr";
  cxId: string;
  patientId: string;
  requestId: string;
  oid: string;
  timestamp: string;
- index?: number;
+ requestChunkId?: string | undefined;
 }) {
  const date = dayjs(timestamp).format("YYYY-MM-DD");
- const indexPart = index ? `_${index}` : "";
- return `${cxId}/${patientId}/${type}/${requestId}_${date}/${oid}${indexPart}.xml`;
+ const requestChunkIdPart = requestChunkId ? `_${requestChunkId}` : "";
+ return `${cxId}/${patientId}/${type}/${requestId}_${date}/${oid}${requestChunkIdPart}.xml`;
 }

packages/core/src/external/carequality/ihe-gateway-v2/outbound/xca/process/dr-response.ts

@@ -187,6 +187,7 @@ async function handleSuccessResponse({
 
  const response: OutboundDocumentRetrievalResp = {
  id: outboundRequest.id,
+ requestChunkId: outboundRequest.requestChunkId,
  patientId: outboundRequest.patientId,
  timestamp: outboundRequest.timestamp,
  requestTimestamp: outboundRequest.timestamp,

packages/core/src/external/carequality/ihe-gateway-v2/outbound/xca/process/error.ts

@@ -74,6 +74,7 @@ export function handleRegistryErrorResponse({
  const operationOutcome = processRegistryErrorList(registryErrorList, outboundRequest);
  return {
  id: outboundRequest.id,
+ requestChunkId: outboundRequest.requestChunkId,
  patientId: outboundRequest.patientId,
  timestamp: outboundRequest.timestamp,
  requestTimestamp: outboundRequest.timestamp,
@@ -110,6 +111,7 @@ export function handleHttpErrorResponse({
  };
  return {
  id: outboundRequest.id,
+ requestChunkId: outboundRequest.requestChunkId,
  timestamp: outboundRequest.timestamp,
  requestTimestamp: outboundRequest.timestamp,
  responseTimestamp: dayjs().toISOString(),
@@ -145,6 +147,7 @@ export function handleEmptyResponse({
  };
  return {
  id: outboundRequest.id,
+ requestChunkId: outboundRequest.requestChunkId,
  patientId: outboundRequest.patientId,
  timestamp: outboundRequest.timestamp,
  requestTimestamp: outboundRequest.timestamp,
@@ -179,6 +182,7 @@ export function handleSchemaErrorResponse({
  };
  return {
  id: outboundRequest.id,
+ requestChunkId: outboundRequest.requestChunkId,
  patientId: outboundRequest.patientId,
  timestamp: outboundRequest.timestamp,
  requestTimestamp: outboundRequest.timestamp,

packages/core/src/external/carequality/ihe-gateway-v2/outbound/xca/send/dq-requests.ts

@@ -55,7 +55,7 @@ export async function sendSignedDqRequest({
  } catch (error: any) {
  const msg = `HTTP/SSL Failure Sending Signed DQ SAML Request ${index + 1}`;
  log(
- `${msg}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.homeCommunityId}, error: ${error}`
+ `${msg}, requestId: ${request.outboundRequest.id}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.homeCommunityId}, error: ${error}`
  );
  if (error?.response?.data) {
  log(`error details: ${JSON.stringify(error?.response?.data)}`);

packages/core/src/external/carequality/ihe-gateway-v2/outbound/xca/send/dr-requests.ts

@@ -36,6 +36,8 @@ export async function sendSignedDrRequest({
  signedXml: request.signedRequest,
  url: request.gateway.url,
  samlCertsAndKeys,
+ oid: request.outboundRequest.gateway.homeCommunityId,
+ requestChunkId: request.outboundRequest.requestChunkId,
  });
  log(
  `Request ${index + 1} sent successfully to: ${request.gateway.url} + oid: ${
@@ -46,7 +48,7 @@ export async function sendSignedDrRequest({
  response: rawResponse,
  outboundRequest: request.outboundRequest,
  gateway: request.gateway,
- index,
+ requestChunkId: request.outboundRequest.requestChunkId,
  });
  return {
  gateway: request.gateway,
@@ -57,13 +59,15 @@ export async function sendSignedDrRequest({
  } catch (error: any) {
  const msg = "HTTP/SSL Failure Sending Signed DR SAML Request";
  log(
- `${msg}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.homeCommunityId}, error: ${error}`
+ `${msg}, requestId ${request.outboundRequest.id}, requestChunkId: ${request.outboundRequest.requestChunkId}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.homeCommunityId}, error: ${error}`
  );
  if (error?.response?.data) {
  const errorDetails = Buffer.isBuffer(error?.response?.data)
  ? error.response.data.toString("utf-8")
  : JSON.stringify(error?.response?.data);
- log(`error details: ${errorDetails}`);
+ log(
+ `batchRequestId: ${request.outboundRequest.id}, requestChunkId: ${request.outboundRequest.requestChunkId}, error details: ${errorDetails}`
+ );
  }
 
  const errorString: string = errorToString(error);

packages/core/src/external/carequality/ihe-gateway-v2/outbound/xcpd/send/xcpd-requests.ts

@@ -53,7 +53,7 @@ export async function sendSignedXcpdRequest({
  } catch (error: any) {
  const msg = "HTTP/SSL Failure Sending Signed XCPD SAML Request";
  log(
- `${msg}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.oid}, error: ${error}`
+ `${msg}, requestId: ${request.outboundRequest.id}, cxId: ${cxId}, patientId: ${patientId}, gateway: ${request.gateway.oid}, error: ${error}`
  );
  if (error?.response?.data) {
  log(`error details: ${JSON.stringify(error?.response?.data)}`);

packages/core/src/external/carequality/ihe-gateway-v2/saml/saml-client.ts

@@ -4,9 +4,10 @@ import axios from "axios";
 import * as AWS from "aws-sdk";
 import dayjs from "dayjs";
 import duration from "dayjs/plugin/duration";
+import { NetworkError } from "@metriport/shared";
 import { SamlCertsAndKeys } from "./security/types";
 import { Config } from "../../../../util/config";
-import { out } from "../../../../util/log";
+import { log as getLog, out } from "../../../../util/log";
 import { MetriportError } from "../../../../util/error/metriport-error";
 import { createMtomContentTypeAndPayload } from "../outbound/xca/mtom/builder";
 import { executeWithNetworkRetries } from "@metriport/shared";
@@ -23,6 +24,20 @@ const { log } = out("Saml Client");
 const httpTimeoutPatientDiscovery = dayjs.duration({ seconds: 60 });
 const httpTimeoutDocumentQuery = dayjs.duration({ seconds: 120 });
 const httpTimeoutDocumentRetrieve = dayjs.duration({ seconds: 120 });
+
+const httpCodesToRetry: NetworkError[] = [
+ "ECONNREFUSED",
+ "ECONNRESET",
+ "ETIMEDOUT",
+ "ECONNABORTED",
+];
+
+const httpCodesToRetryPatientDiscovery: NetworkError[] = [...httpCodesToRetry];
+
+const httpCodesToRetryDocumentQuery: NetworkError[] = [...httpCodesToRetry, "ERR_BAD_RESPONSE"];
+
+const httpCodesToRetryDocumentRetrieve: NetworkError[] = [...httpCodesToRetry, "ERR_BAD_RESPONSE"];
+
 const initialDelay = dayjs.duration({ seconds: 3 });
 const maxPayloadSize = Infinity;
 let rejectUnauthorized = true;
@@ -102,13 +117,15 @@ export async function sendSignedXml({
  "Cache-Control": "no-cache",
  },
  httpsAgent: agent,
+ maxBodyLength: maxPayloadSize,
+ maxContentLength: maxPayloadSize,
  });
  },
  {
  initialDelay: initialDelay.asMilliseconds(),
  maxAttempts: isDq ? 4 : 3,
  //TODO: This introduces retry on timeout without needing to specify the http Code: https://github.com/metriport/metriport/pull/2285. Remove once PR is merged
- httpCodesToRetry: ["ECONNREFUSED", "ECONNRESET", "ETIMEDOUT", "ECONNABORTED"],
+ httpCodesToRetry: isDq ? httpCodesToRetryDocumentQuery : httpCodesToRetryPatientDiscovery,
  }
  );
 
@@ -119,10 +136,14 @@ export async function sendSignedXmlMtom({
  signedXml,
  url,
  samlCertsAndKeys,
+ oid,
+ requestChunkId,
 }: {
  signedXml: string;
  url: string;
  samlCertsAndKeys: SamlCertsAndKeys;
+ oid: string;
+ requestChunkId: string | undefined;
 }): Promise<{ mtomParts: MtomAttachments; rawResponse: Buffer }> {
  const trustedKeyStore = await getTrustedKeyStore();
  const agent = new https.Agent({
@@ -136,6 +157,7 @@ export async function sendSignedXmlMtom({
  secureOptions: constants.SSL_OP_ALLOW_UNSAFE_LEGACY_RENEGOTIATION,
  });
 
+ const logger = getLog(`sendSignedXmlMtom, oid: ${oid}, requestChunkId: ${requestChunkId}`);
  const { contentType, payload } = createMtomContentTypeAndPayload(signedXml);
  const response = await executeWithNetworkRetries(
  async () => {
@@ -156,13 +178,8 @@ export async function sendSignedXmlMtom({
  initialDelay: initialDelay.asMilliseconds(),
  maxAttempts: 4,
  //TODO: This introduces retry on timeout without needing to specify the http Code: https://github.com/metriport/metriport/pull/2285. Remove once PR is merged
- httpCodesToRetry: [
- "ECONNREFUSED",
- "ECONNRESET",
- "ETIMEDOUT",
- "ECONNABORTED",
- "ERR_BAD_RESPONSE",
- ],
+ httpCodesToRetry: httpCodesToRetryDocumentRetrieve,
+ log: logger,
  }
  );
 

packages/ihe-gateway-sdk/src/models/shared.ts

@@ -31,6 +31,7 @@ export type SamlAttributes = z.infer<typeof SamlAttributesSchema>;
 
 export const baseRequestSchema = z.object({
  id: z.string(),
+ requestChunkId: z.string().optional(),
  cxId: z.string().optional(),
  timestamp: z.string(),
  samlAttributes: SamlAttributesSchema,
@@ -75,6 +76,7 @@ export type XCPDPatientId = z.infer<typeof externalGatewayPatientSchema>;
 
 export const baseResponseSchema = z.object({
  id: z.string(),
+ requestChunkId: z.string().nullish(),
  timestamp: z.string(),
  /** timestamp right after external gateway response */
  responseTimestamp: z.string(),