diff --git a/core/packages/gax/src/fallbackRest.ts b/core/packages/gax/src/fallbackRest.ts index b6e5f7621ea..14c9cef23e8 100644 --- a/core/packages/gax/src/fallbackRest.ts +++ b/core/packages/gax/src/fallbackRest.ts @@ -90,6 +90,7 @@ export function decodeResponse( rpc: protobuf.Method, ok: boolean, response: Buffer | ArrayBuffer, + httpStatusCode?: number, ): {} { // eslint-disable-next-line n/no-unsupported-features/node-builtins const decodedString = new TextDecoder().decode(response); @@ -99,6 +100,17 @@ export function decodeResponse( const json = JSON.parse(decodedString); if (!ok) { const error = GoogleError.parseHttpError(json); + // `parseHttpError` reads the status out of the response body and maps it + // onto the gRPC `code`, keeping no record of the status the transport + // actually received — and the body's status can differ from it, or be + // missing entirely. Record the received one when the caller knows it. + // + // Optional because `decodeResponse` is also called from + // `streamArrayParser`, which only ever decodes an already-successful body + // and so has no status to pass. + if (httpStatusCode !== undefined) { + error.httpStatusCode = httpStatusCode; + } throw error; } const message = serializer.fromProto3JSON(rpc.resolvedResponseType!, json); diff --git a/core/packages/gax/src/fallbackServiceStub.ts b/core/packages/gax/src/fallbackServiceStub.ts index b096ffc81f6..0722ecbd43f 100644 --- a/core/packages/gax/src/fallbackServiceStub.ts +++ b/core/packages/gax/src/fallbackServiceStub.ts @@ -14,7 +14,9 @@ * limitations under the License. */ -import type {Response as NodeFetchResponse} from 'node-fetch' with {'resolution-mode': 'import'}; +import type {Response as NodeFetchResponse} from 'node-fetch' with { + 'resolution-mode': 'import', +}; import {AuthClient, GoogleAuth, gaxios} from 'google-auth-library'; import * as serializer from 'proto3-json-serializer'; @@ -35,8 +37,7 @@ import type {Agent as HttpsAgent} from 'https'; // - https://github.com/node-fetch/node-fetch#custom-agent // - https://github.com/googleapis/gax-nodejs/pull/1534 let agentOption: - | ((parsedUrl: {protocol: string}) => HttpAgent | HttpsAgent) - | null = null; + ((parsedUrl: {protocol: string}) => HttpAgent | HttpsAgent) | null = null; if (isNodeJS()) { const http = require('http'); const https = require('https'); @@ -221,6 +222,7 @@ export function generateServiceStub( rpc: protobuf.Method, ok: boolean, response: Buffer | ArrayBuffer, + httpStatusCode?: number, ) => {}, numericEnums: boolean, minifyJson: boolean, @@ -426,12 +428,20 @@ export function generateServiceStub( ); return; } else { + // Captured here because the decoded value below is also named + // `response` and shadows the fetch response. + const httpStatusCode = response.status; return Promise.all([ Promise.resolve(response.ok), response.arrayBuffer(), ]) .then(([ok, buffer]: [boolean, Buffer | ArrayBuffer]) => { - const response = responseDecoder(rpc, ok, buffer); + const response = responseDecoder( + rpc, + ok, + buffer, + httpStatusCode, + ); callback!(null, response); return; }) diff --git a/core/packages/gax/src/googleError.ts b/core/packages/gax/src/googleError.ts index 42a64f60b1a..961fab6bdf7 100644 --- a/core/packages/gax/src/googleError.ts +++ b/core/packages/gax/src/googleError.ts @@ -32,6 +32,19 @@ const NUM_OF_PARTS_IN_PROTO_TYPE_NAME = 2; export class GoogleError extends Error { code?: Status; + /** + * The HTTP response status received by the REST fallback transport. + * + * `code` holds the gRPC status the response was mapped to, which is lossy: + * `rpcCodeFromHttpStatusCode` collapses whole ranges (every unmapped 5xx + * becomes INTERNAL), so the original status cannot be recovered from it. + * Telemetry reports the two separately, so the received status is kept here + * as well. + * + * Undefined for gRPC calls, and for fallback failures that never produced a + * response at all, such as an expired deadline or a connection error. + */ + httpStatusCode?: number; note?: string; metadata?: Metadata; statusDetails?: string | protobuf.Message<{}>[]; diff --git a/core/packages/gax/src/observability/TracerHelper.ts b/core/packages/gax/src/observability/TracerHelper.ts index c444b40360f..9f06e8c59a6 100644 --- a/core/packages/gax/src/observability/TracerHelper.ts +++ b/core/packages/gax/src/observability/TracerHelper.ts @@ -15,7 +15,13 @@ */ import {EventEmitter} from 'events'; -import {Span, SpanStatusCode, trace, Tracer} from '@opentelemetry/api'; +import { + Attributes, + Span, + SpanStatusCode, + trace, + Tracer, +} from '@opentelemetry/api'; import {APICallback, GaxCallResult} from '../apitypes'; import {Status} from '../status'; @@ -105,6 +111,33 @@ function resolveErrorType(e: Error): string { return e.constructor?.name ?? e.name; } +/** + * Resolves the gRPC status reported for a failed call, as its name. + * + * Zero is treated as absent rather than as `OK`, for the same reason as in + * `resolveErrorType`: it is the proto3 default for an unset field, so a failed + * call must not be labelled `OK`. + */ +function resolveRpcStatusName(e: unknown): string { + const code = (e as {code?: unknown} | null)?.code; + if ( + typeof code === 'number' && + code !== Status.OK && + Status[code] !== undefined + ) { + return Status[code]; + } + return Status[Status.UNKNOWN]; +} + +/** + * Reads the HTTP response status recorded on a fallback error. + */ +function resolveHttpStatusCode(e: unknown): number | undefined { + const code = (e as {httpStatusCode?: unknown} | null)?.httpStatusCode; + return typeof code === 'number' ? code : undefined; +} + /** * Checks if a value behaves like a Promise or Thenable. * @@ -333,6 +366,13 @@ export function traceCall( let spanEnded = false; let errorRecorded = false; + // Resolved from the error when one is reported, and defaulted to success + // in endSpan otherwise. Held here rather than written immediately so that + // every completion path — promise, stream, callback, synchronous throw — + // emits them from the same place. + let rpcStatusName: string | undefined; + let httpStatusCode: number | undefined; + // Marks the span failed. Kept separate from recordError so paths that are // failures but not exceptions can set the status without emitting a // misleading exception event. @@ -341,19 +381,49 @@ export function traceCall( span.setStatus({code: SpanStatusCode.ERROR, message}); }; + // The gRPC status is reported for both transports, because it is the one + // status gax resolves on every call and the only one a caller can compare + // across them. The transport-specific attribute is an alias of it on gRPC, + // and the received HTTP status on the fallback, which is a different value + // rather than a restatement of the same one. + // + // Written from one place so the two can never disagree. + const setStatusAttributes = () => { + const attributes: Attributes = { + 'rpc.response.status_code': rpcStatusName, + }; + if (dynamicArgs.rpcType === 'grpc') { + attributes['grpc.response.status_code'] = rpcStatusName; + } else if (httpStatusCode !== undefined) { + attributes['http.response.status_code'] = httpStatusCode; + } + span.setAttributes(attributes); + }; + // Every path ends here, so the status is resolved in one place: ERROR if // anything reported a failure, OK otherwise. const endSpan = () => { if (!spanEnded) { spanEnded = true; if (!errorRecorded) { + rpcStatusName = Status[Status.OK]; + // Nothing carries the response status back on a successful fallback + // call, and success means a 2xx, so 200 is the only value available. + // A legacy Apiary 204 is therefore also reported as 200. + httpStatusCode = 200; span.setStatus({code: SpanStatusCode.OK}); } + setStatusAttributes(); span.end(); } }; const recordError = (e: unknown) => { + // Resolved for every failure, including non-Error throws: those carry no + // status, and resolveRpcStatusName reports UNKNOWN for them, which is + // the right answer for a call that failed for an unmapped reason. + rpcStatusName = resolveRpcStatusName(e); + httpStatusCode = resolveHttpStatusCode(e); if (e instanceof Error) { span.setAttributes({ 'error.message': e.message, diff --git a/core/packages/gax/test/unit/grpc-fallback.ts b/core/packages/gax/test/unit/grpc-fallback.ts index b3d0df1aa10..a708b8e4fad 100644 --- a/core/packages/gax/test/unit/grpc-fallback.ts +++ b/core/packages/gax/test/unit/grpc-fallback.ts @@ -458,6 +458,35 @@ describe('grpc-fallback', () => { }); }); + it('should record the received http status on the error', async () => { + const requestObject = {content: 'test-content'}; + + // The body reports 400 while the response itself is a 503. `code` is + // derived from the body, so a status read back off the error can only be + // the received one if the two differ. + setMockFallbackHttpResponse( + gaxGrpc, + new Response( + JSON.stringify({error: {code: 400, message: 'mismatched status'}}), + {status: 503}, + ), + ); + + const echoStub = await gaxGrpc.createStub(echoService, stubOptions); + await new Promise((resolve, reject) => { + echoStub.echo(requestObject, {}, {}, (err?: Error) => { + try { + assert(err instanceof GoogleError); + assert.strictEqual(err.code, Status.INVALID_ARGUMENT); + assert.strictEqual(err.httpStatusCode, 503); + resolve(); + } catch (e) { + reject(e); + } + }); + }); + }); + it('should promote ErrorInfo if exist in fallback-rest error', async () => { const requestObject = {content: 'test-content'}; // example of an actual google.rpc.Status error message returned by Translate API @@ -1357,5 +1386,26 @@ describe('grpc-fallback', () => { assert.strictEqual(err.code, Status.UNAVAILABLE); assert.notStrictEqual(err.code as number, 503); }); + + it('should decode a resolved error response and record its http status', async () => { + // 500 now passes `validateStatus`, so it resolves and is decoded, which + // is what lets the received HTTP status be recorded alongside the + // gRPC code the body maps to. + setMockFallbackHttpResponse( + gaxGrpc, + new Response( + JSON.stringify({ + error: {code: 500, message: 'server blew up', status: 'INTERNAL'}, + }), + {status: 500, headers: {'Content-Type': 'application/json'}}, + ), + ); + + const err = await callEcho(); + + assert(err instanceof GoogleError); + assert.strictEqual(err.code, Status.INTERNAL); + assert.strictEqual(err.httpStatusCode, 500); + }); }); }); diff --git a/core/packages/gax/test/unit/otelHarness.ts b/core/packages/gax/test/unit/otelHarness.ts index 77c9e98e0c1..0686de71804 100644 --- a/core/packages/gax/test/unit/otelHarness.ts +++ b/core/packages/gax/test/unit/otelHarness.ts @@ -199,6 +199,123 @@ export class OtelHarness { ); } } + + /** + * The three response status attributes carried by a traced call. + * + * @param {ReadableSpan} span - The span to read. + * @returns {ResponseStatusAttributes} The attributes, each undefined if absent. + */ + responseStatus(span: ReadableSpan): ResponseStatusAttributes { + return { + rpc: span.attributes['rpc.response.status_code'] as string | undefined, + grpc: span.attributes['grpc.response.status_code'] as string | undefined, + http: span.attributes['http.response.status_code'] as number | undefined, + }; + } + + /** + * Asserts the response status attributes of a traced call. + * + * The transport-specific attribute is not named by the caller. It is derived + * from the span's own `gcp.method.type`, so a test cannot assert a + * combination the tracer is not supposed to produce — such as an HTTP status + * on a gRPC span. Both the presence of the attribute that applies and the + * absence of the one that does not are checked, because the second half is + * what catches an attribute leaking onto the wrong transport. + * + * `httpStatus` is only meaningful on a fallback span. Omitting it there + * asserts that no HTTP status was reported, which is the expected result for + * a failure that never received a response, such as an expired deadline. + * + * @param {object} expected - Expected status values. + * @param {string} expected.rpcStatus - gRPC status name, e.g. 'OK' or 'NOT_FOUND'. + * @param {number} [expected.httpStatus] - HTTP status expected on a fallback span. + * @param {object} [options] - Span selection. + * @param {string} [options.tracerName] - Restrict the lookup to one instrumentation scope. + * @param {ReadableSpan} [options.span] - Span to check; defaults to the only exported span. + */ + assertResponseStatus( + expected: {rpcStatus: string; httpStatus?: number}, + options: {tracerName?: string; span?: ReadableSpan} = {}, + ): void { + const target = options.span ?? this.requireSingleSpan(options.tracerName); + const actual = this.responseStatus(target); + const transport = target.attributes['gcp.method.type']; + const where = `span '${target.name}'`; + + assert.ok( + transport === 'grpc' || transport === 'http', + `${where} has gcp.method.type ${JSON.stringify(transport)}; the ` + + 'transport-specific status attribute cannot be checked without it. ' + + 'Was this span produced by traceCall?', + ); + + assert.strictEqual( + actual.rpc, + expected.rpcStatus, + `expected ${where} to report rpc.response.status_code ` + + `${JSON.stringify(expected.rpcStatus)}, got ${JSON.stringify(actual.rpc)}. ` + + 'This attribute is reported on every call, on both transports.', + ); + + if (transport === 'grpc') { + assert.strictEqual( + actual.grpc, + expected.rpcStatus, + `expected ${where} to report grpc.response.status_code ` + + `${JSON.stringify(expected.rpcStatus)}, got ${JSON.stringify(actual.grpc)}. ` + + 'On a gRPC span it mirrors rpc.response.status_code.', + ); + assert.strictEqual( + actual.http, + undefined, + `${where} is a gRPC span but reported http.response.status_code ` + + `${JSON.stringify(actual.http)}. A gRPC call has no HTTP status, ` + + 'not even a synthesized one.', + ); + assert.strictEqual( + expected.httpStatus, + undefined, + 'assertResponseStatus was given an expected httpStatus for a gRPC ' + + 'span, which can never hold one. Drop it, or assert against a ' + + 'fallback span.', + ); + return; + } + + assert.strictEqual( + actual.grpc, + undefined, + `${where} is a fallback span but reported grpc.response.status_code ` + + `${JSON.stringify(actual.grpc)}. The gRPC status is reported as ` + + 'rpc.response.status_code there, not under the grpc.* name.', + ); + assert.strictEqual( + actual.http, + expected.httpStatus, + expected.httpStatus === undefined + ? `expected ${where} to report no http.response.status_code, got ` + + `${JSON.stringify(actual.http)}. It is only reported when a ` + + 'response was actually received.' + : `expected ${where} to report http.response.status_code ` + + `${expected.httpStatus}, got ${JSON.stringify(actual.http)}. ` + + 'This is the status the transport received, which is not ' + + 'recoverable from the gRPC status it was mapped to.', + ); + } +} + +/** + * The response status attributes read off a traced span. + */ +export interface ResponseStatusAttributes { + /** `rpc.response.status_code`: gRPC status name, reported on both transports. */ + rpc: string | undefined; + /** `grpc.response.status_code`: gRPC spans only. */ + grpc: string | undefined; + /** `http.response.status_code`: fallback spans that received a response. */ + http: number | undefined; } /** diff --git a/core/packages/gax/test/unit/tracerHelper.ts b/core/packages/gax/test/unit/tracerHelper.ts index 7e87577f9bf..65aa37a548f 100644 --- a/core/packages/gax/test/unit/tracerHelper.ts +++ b/core/packages/gax/test/unit/tracerHelper.ts @@ -315,6 +315,169 @@ describe('TracerHelper', () => { assert.strictEqual(spans[0].attributes['gcp.method.type'], 'http'); }); + describe('response status attributes', () => { + const httpDynamicArgs: DynamicTraceContext = { + clientName: 'ComputeClient', + methodName: 'InsertInstance', + rpcType: 'http', + }; + + it('reports OK on a successful grpc call', async () => { + await traceCall(dynamicArgs, staticArgs, async () => 'ok'); + + harness.assertResponseStatus({rpcStatus: 'OK'}); + }); + + it('reports OK and 200 on a successful http call', async () => { + await traceCall(httpDynamicArgs, staticArgs, async () => 'ok'); + + harness.assertResponseStatus({rpcStatus: 'OK', httpStatus: 200}); + }); + + it('reports the gRPC status name on a failed grpc call', async () => { + // Shape produced by grpc-js callErrorFromStatus. + const error = Object.assign(new Error('5 NOT_FOUND'), {code: 5}); + + await assert.rejects(async () => { + await traceCall(dynamicArgs, staticArgs, async () => { + throw error; + }); + }); + + harness.assertResponseStatus({rpcStatus: 'NOT_FOUND'}); + }); + + it('reports the received http status alongside the mapped gRPC status', async () => { + // 418 is unmapped, so rpcCodeFromHttpStatusCode collapses it to + // FAILED_PRECONDITION. The received status is therefore not + // recoverable from `code`, which is why it is carried separately. + const error = new GoogleError('teapot'); + error.code = Status.FAILED_PRECONDITION; + error.httpStatusCode = 418; + + await assert.rejects(async () => { + await traceCall(httpDynamicArgs, staticArgs, async () => { + throw error; + }); + }); + + harness.assertResponseStatus({ + rpcStatus: 'FAILED_PRECONDITION', + httpStatus: 418, + }); + }); + + it('omits the http status when no response was received', async () => { + // What toDeadlineExceeded produces: a real gRPC status, but no + // response and so no HTTP status to report. Omitting httpStatus + // asserts the attribute is absent. + const error = new GoogleError('Deadline exceeded'); + error.code = Status.DEADLINE_EXCEEDED; + + await assert.rejects(async () => { + await traceCall(httpDynamicArgs, staticArgs, async () => { + throw error; + }); + }); + + harness.assertResponseStatus({rpcStatus: 'DEADLINE_EXCEEDED'}); + }); + + it('reports UNKNOWN for a failure carrying no gRPC status', async () => { + const error = Object.assign(new Error('connect ECONNREFUSED'), { + code: 'ECONNREFUSED', + }); + + await assert.rejects(async () => { + await traceCall(dynamicArgs, staticArgs, async () => { + throw error; + }); + }); + + harness.assertResponseStatus({rpcStatus: 'UNKNOWN'}); + }); + + it('reports UNKNOWN rather than OK for a zero status code', async () => { + // Zero is the proto3 default for an unset code, so a failed call must + // not be labelled OK. + const error = Object.assign(new Error('unset code'), {code: 0}); + + await assert.rejects(async () => { + await traceCall(dynamicArgs, staticArgs, async () => { + throw error; + }); + }); + + harness.assertResponseStatus({rpcStatus: 'UNKNOWN'}); + }); + + it('reports UNKNOWN when a non-Error is thrown', async () => { + await assert.rejects(async () => { + await traceCall(dynamicArgs, staticArgs, async () => { + throw 'plain string failure'; + }); + }); + + harness.assertResponseStatus({rpcStatus: 'UNKNOWN'}); + }); + + it('reports the status of a stream failure', () => { + const emitter = new EventEmitter(); + const error = new GoogleError('stream failed'); + error.code = Status.UNAVAILABLE; + + traceCall(dynamicArgs, staticArgs, () => emitter, true); + emitter.emit('error', error); + + harness.assertResponseStatus({rpcStatus: 'UNAVAILABLE'}); + }); + + it('reports the status of a failure delivered to a callback', done => { + const error = new GoogleError('permission denied'); + error.code = Status.PERMISSION_DENIED; + + // Mimics an API caller that returns OngoingCall (no `.promise`), so + // the span is bound to the callback rather than to a promise. + const returned = traceCall( + dynamicArgs, + staticArgs, + tracedCallback => { + tracedCallback!(error); + return undefined as unknown as ResultTuple; + }, + false, + () => { + harness.assertResponseStatus({rpcStatus: 'PERMISSION_DENIED'}); + done(); + }, + ); + + assert.strictEqual(returned, undefined); + }); + + // The harness derives the transport from the span, so these guard the + // guard: a regression that moved an attribute onto the wrong transport + // has to be caught rather than quietly accepted. + it('rejects an expected http status on a grpc span', async () => { + await traceCall(dynamicArgs, staticArgs, async () => 'ok'); + + assert.throws( + () => + harness.assertResponseStatus({rpcStatus: 'OK', httpStatus: 200}), + /can never hold one/, + ); + }); + + it('rejects a grpc status name that does not match', async () => { + await traceCall(dynamicArgs, staticArgs, async () => 'ok'); + + assert.throws( + () => harness.assertResponseStatus({rpcStatus: 'NOT_FOUND'}), + /rpc\.response\.status_code/, + ); + }); + }); + it('manages span lifetime for resolved promises', async () => { const result = await traceCall(dynamicArgs, staticArgs, () => Promise.resolve('async-result'),