Skip to content

Commit 6d9dc09

Browse files
committed
fix(gax): fix response.payload extraction, deduplication latch, and outer span fallback in logNetworkAttempt
1 parent 4ab208d commit 6d9dc09

7 files changed

Lines changed: 585 additions & 55 deletions

File tree

‎core/packages/gax/src/fallbackRest.ts‎

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@
1919
import * as serializer from 'proto3-json-serializer';
2020
import {defaultToObjectOptions} from './fallback';
2121
import {FetchParameters, FetchParametersMethod} from './fallbackServiceStub';
22-
import {GoogleError} from './googleError';
22+
import {GoogleError, setRawHttpResponsePayload} from './googleError';
2323
import {rpcCodeFromHttpStatusCode} from './status';
2424
import {getMatchedUrlTemplate, transcode} from './transcoding';
2525

@@ -160,7 +160,7 @@ export function decodeResponse(
160160
if (ok) {
161161
throw err;
162162
}
163-
throw _undecodableErrorResponse(
163+
const undecodableError = _undecodableErrorResponse(
164164
rpc,
165165
httpStatusCode,
166166
`the response body is not JSON: ${
@@ -170,6 +170,8 @@ export function decodeResponse(
170170
}`,
171171
err,
172172
);
173+
setRawHttpResponsePayload(undecodableError, decodedString);
174+
throw undecodableError;
173175
}
174176
if (!ok) {
175177
let error: GoogleError;
@@ -179,12 +181,14 @@ export function decodeResponse(
179181
// `parseHttpError` indexes into the body, so JSON that parses but is not
180182
// an object — `null`, a string, a number — fails there for the same
181183
// reason an HTML body fails above, and must not lose the status either.
182-
throw _undecodableErrorResponse(
184+
const undecodableError = _undecodableErrorResponse(
183185
rpc,
184186
httpStatusCode,
185187
'the response body is not a JSON error object',
186188
err,
187189
);
190+
setRawHttpResponsePayload(undecodableError, decodedString);
191+
throw undecodableError;
188192
}
189193
// `parseHttpError` reads the status out of the response body and maps it
190194
// onto the gRPC `code`, keeping no record of the status the transport
@@ -197,6 +201,7 @@ export function decodeResponse(
197201
if (httpStatusCode !== undefined) {
198202
error.httpStatusCode = httpStatusCode;
199203
}
204+
setRawHttpResponsePayload(error, decodedString);
200205
throw error;
201206
}
202207
const message = serializer.fromProto3JSON(rpc.resolvedResponseType!, json);

‎core/packages/gax/src/fallbackServiceStub.ts‎

Lines changed: 48 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@ import * as serializer from 'proto3-json-serializer';
2424
import {isNodeJS} from './featureDetection';
2525
import {StreamArrayParser} from './streamArrayParser';
2626
import {defaultToObjectOptions} from './fallback';
27-
import {GoogleError} from './googleError';
27+
import {GoogleError, setRawHttpResponsePayload} from './googleError';
2828
import {setAttemptHttpMethod} from './observability/TracerHelper';
2929
import {rpcCodeFromHttpStatusCode, Status} from './status';
3030
import {pipeline, PipelineSource} from 'stream';
@@ -234,6 +234,43 @@ function _parseHttpErrorFromRejection(
234234
return undefined;
235235
}
236236

237+
const GAXIOS_REDACTED_BODY =
238+
'<<REDACTED> - See `errorRedactor` option in `gaxios` for configuration>.';
239+
240+
function _isStreamLike(value: unknown): boolean {
241+
if (!value || typeof value !== 'object') {
242+
return false;
243+
}
244+
const stream = value as {pipe?: unknown; getReader?: unknown};
245+
return (
246+
typeof stream.pipe === 'function' || typeof stream.getReader === 'function'
247+
);
248+
}
249+
250+
function _extractRawPayloadFromRejection(
251+
err: Error,
252+
responseData: unknown,
253+
httpStatus: number,
254+
): unknown {
255+
if (
256+
responseData !== undefined &&
257+
responseData !== null &&
258+
responseData !== '' &&
259+
responseData !== GAXIOS_REDACTED_BODY &&
260+
!_isStreamLike(responseData)
261+
) {
262+
return responseData;
263+
}
264+
if (
265+
err.message.length > 0 &&
266+
err.message !== GAXIOS_REDACTED_BODY &&
267+
err.message !== `Request failed with status code ${httpStatus}`
268+
) {
269+
return err.message;
270+
}
271+
return undefined;
272+
}
273+
237274
function _toGoogleError(err: unknown, outcome: CallOutcome): unknown {
238275
if (err instanceof GoogleError) {
239276
return err;
@@ -264,13 +301,22 @@ function _toGoogleError(err: unknown, outcome: CallOutcome): unknown {
264301
? fetchError.status
265302
: fetchError.response?.status;
266303
if (typeof httpStatus === 'number') {
304+
const responseData = fetchError.response?.data;
267305
const parsedError =
268-
_parseHttpErrorFromRejection(err, fetchError.response?.data) ?? error;
306+
_parseHttpErrorFromRejection(err, responseData) ?? error;
269307
parsedError.cause = err;
270308
if (typeof parsedError.code !== 'number') {
271309
parsedError.code = rpcCodeFromHttpStatusCode(httpStatus);
272310
}
273311
parsedError.httpStatusCode = httpStatus;
312+
const rawPayload = _extractRawPayloadFromRejection(
313+
err,
314+
responseData,
315+
httpStatus,
316+
);
317+
if (rawPayload !== undefined) {
318+
setRawHttpResponsePayload(parsedError, rawPayload);
319+
}
274320
return parsedError;
275321
}
276322

‎core/packages/gax/src/googleError.ts‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,34 @@ const UNKNOWN_TYPE_ENCONDED_ERROR_PREFIX = 'Unknown type encoded in';
2929
const UNKNOWN_TYPE_NO_SUCH_TYPE = 'no such type';
3030

3131
const NUM_OF_PARTS_IN_PROTO_TYPE_NAME = 2;
32+
const RAW_HTTP_RESPONSE_PAYLOAD = Symbol.for(
33+
'google-gax.rawHttpResponsePayload',
34+
);
35+
36+
/**
37+
* Attaches the full raw HTTP response body non-enumerably to a GoogleError so
38+
* telemetry debug logging can report `response.payload` without altering
39+
* standard error formatting or serialization.
40+
*/
41+
export function setRawHttpResponsePayload(
42+
err: GoogleError,
43+
payload: unknown,
44+
): void {
45+
Object.defineProperty(err, RAW_HTTP_RESPONSE_PAYLOAD, {
46+
value: payload,
47+
configurable: true,
48+
enumerable: false,
49+
writable: true,
50+
});
51+
}
52+
53+
/**
54+
* Reads the raw HTTP response body previously attached by
55+
* {@link setRawHttpResponsePayload}, if any.
56+
*/
57+
export function getRawHttpResponsePayload(err: object): unknown {
58+
return (err as Record<symbol, unknown>)[RAW_HTTP_RESPONSE_PAYLOAD];
59+
}
3260

3361
export class GoogleError extends Error {
3462
code?: Status;

‎core/packages/gax/src/observability/LoggerHelper.ts‎

Lines changed: 30 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -30,11 +30,11 @@ import {
3030
import {
3131
resolveErrorInfoDomain,
3232
resolveErrorInfoMetadataAttributes,
33+
resolveErrorResponsePayload,
3334
resolveErrorType,
3435
resolveExceptionMessage,
3536
resolveExceptionStacktrace,
3637
resolveExceptionType,
37-
resolveResponsePayload,
3838
resolveResponseStatusCode,
3939
resolveRpcStatusName,
4040
} from './errorUtil';
@@ -61,19 +61,15 @@ export interface LogPayload {
6161
}
6262

6363
/**
64-
* Resolves a `LogSeverity` value across `google-logging-utils` versions where
65-
* `LogSeverity` may be exported as a type only.
64+
* Resolves a `LogSeverity` enum value. Until a `google-logging-utils` release
65+
* containing #9718 is published to npm (this repo uses `link-workspace-packages=false`),
66+
* the published package exports `LogSeverity` as a type only while each enum member's
67+
* runtime value equals its uppercase level string.
6668
*/
6769
function resolveLogSeverity(
6870
level: 'DEBUG' | 'INFO' | 'WARNING' | 'ERROR',
6971
): loggingUtils.LogSeverity {
70-
return (
71-
(
72-
loggingUtils as {
73-
LogSeverity?: Record<string, loggingUtils.LogSeverity>;
74-
}
75-
).LogSeverity?.[level] ?? (level as loggingUtils.LogSeverity)
76-
);
72+
return level as loggingUtils.LogSeverity;
7773
}
7874

7975
/**
@@ -153,22 +149,32 @@ export function buildLogAttributes(
153149

154150
/**
155151
* Executes `fn` and attaches stream, promise, callback, or synchronous error
156-
* handlers to invoke `onError` when the operation fails.
152+
* handlers to invoke `onError` at most once when the operation fails.
157153
*/
158154
function executeLoggedOperation<T>(
159155
fn: (loggedCallback?: APICallback) => T,
160156
onError: (err: unknown) => void,
161157
isStreamCall: boolean,
162158
userCallback?: APICallback,
163159
): T {
160+
// Latch to emit at most one log per invocation across execution boundaries.
161+
let hasLogged = false;
162+
const logOnce = (err: unknown) => {
163+
if (hasLogged) {
164+
return;
165+
}
166+
hasLogged = true;
167+
onError(err);
168+
};
169+
164170
// Wrap user callback to log RPC errors before forwarding.
165171
let callbackInvoked = false;
166172
const loggedCallback: APICallback | undefined = userCallback
167173
? function (this: unknown, ...args: Parameters<APICallback>) {
168174
callbackInvoked = true;
169175
const err = args[0];
170176
if (err) {
171-
onError(err);
177+
logOnce(err);
172178
}
173179
userCallback.apply(this, args);
174180
}
@@ -179,15 +185,15 @@ function executeLoggedOperation<T>(
179185
const result = fn(loggedCallback);
180186
const promiseTarget = !isStreamCall ? getPromiseTarget(result) : null;
181187
if (isStreamCall && result instanceof EventEmitter) {
182-
handleStream(result, onError, () => {}, Boolean(loggedCallback));
188+
handleStream(result, logOnce, () => {}, Boolean(loggedCallback));
183189
} else if (promiseTarget) {
184-
handlePromise(promiseTarget, onError, () => {});
190+
handlePromise(promiseTarget, logOnce, () => {});
185191
}
186192
return result;
187193
} catch (syncErr) {
188194
// Avoid logging errors thrown inside userCallback after RPC completion.
189195
if (!callbackInvoked) {
190-
onError(syncErr);
196+
logOnce(syncErr);
191197
}
192198
throw syncErr;
193199
}
@@ -213,18 +219,10 @@ export function logCall<T = GaxCallResult>(
213219
isStreamCall = false,
214220
userCallback?: APICallback,
215221
): T {
216-
// Latch to emit at most one warning log per logical request.
217-
let hasLoggedL3 = false;
218222
// Snapshot initial context in case async rejection loses active context.
219223
const initialContext = context.active();
220224

221225
const emitL3WarnLog = (err: unknown) => {
222-
// Suppress duplicate emissions for the same call.
223-
if (hasLoggedL3) {
224-
return;
225-
}
226-
hasLoggedL3 = true;
227-
228226
// Resolve logger and active T3 client request span (or outer OpenTelemetry span when GAX tracing is disabled).
229227
const logger = getGaxLogger(staticArgs?.gcpClientService);
230228
const activeTrace = getActiveTraceContext();
@@ -288,20 +286,22 @@ export function logNetworkAttempt<T = GaxCallResult>(
288286
const initialContext = context.active();
289287

290288
const emitL4DebugLog = (err: unknown) => {
291-
// Resolve logger and active T4 attempt span context for this attempt.
289+
// Resolve logger and active T4 attempt span (or outer OpenTelemetry span when GAX tracing is disabled).
292290
const logger = getGaxLogger(staticArgs?.gcpClientService);
291+
const activeTrace = getActiveTraceContext();
292+
const initialTrace = getActiveTraceContext(initialContext);
293293
const attemptSpan =
294-
getActiveTraceContext()?.attemptSpan ??
295-
getActiveTraceContext(initialContext)?.attemptSpan;
294+
activeTrace?.attemptSpan ??
295+
initialTrace?.attemptSpan ??
296+
activeTrace?.span ??
297+
initialTrace?.span;
296298
const spanContext = attemptSpan?.spanContext();
297299
const traceId = spanContext?.traceId;
298300
const spanId = spanContext?.spanId;
299301

300-
// Build structured log attributes and attach attempt metadata payload.
302+
// Build structured log attributes and attach raw attempt response payload when present.
301303
const attributes = buildLogAttributes(err, attemptDynamicArgs, staticArgs);
302-
const responsePayload = resolveResponsePayload(
303-
(err as {metadata?: unknown} | null | undefined)?.metadata,
304-
);
304+
const responsePayload = resolveErrorResponsePayload(err);
305305
if (responsePayload !== undefined) {
306306
attributes['response.payload'] = responsePayload;
307307
}

0 commit comments

Comments
 (0)