Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix(hapi-instrumentation): close spans on errors in instrumented functions #589

Merged
merged 7 commits into from Aug 9, 2021
Expand Up @@ -337,15 +337,25 @@ export class HapiInstrumentation extends InstrumentationBase {
const span = instrumentation.tracer.startSpan(metadata.name, {
attributes: metadata.attributes,
});
let res;
await api.context.with(
api.trace.setSpan(api.context.active(), span),
async () => {
res = await method(...params);
}
);
span.end();
return res;
try {
let res;
await api.context.with(
api.trace.setSpan(api.context.active(), span),
async () => {
res = await method(...params);
}
);
return res;
} catch (err) {
span.recordException(err);
span.setStatus({
code: api.SpanStatusCode.ERROR,
message: err.message,
});
throw err;
} finally {
span.end();
}
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

contex.with passes return values through so the closure is not required here.
This or something similar should work:

        try {
          return api.context.with(
            api.trace.setSpan(api.context.active(), span),
            () => method(...params)
          );
        } catch (err) {
          span.recordException(err);
          span.setStatus({
            code: api.SpanStatusCode.ERROR,
            message: err.message,
          });
          throw err;
        } finally {
          span.end();
        }

Additionally, with also takes arguments to be passed to the function, so it can be simplified even further:

        try {
          return api.context.with(
            api.trace.setSpan(api.context.active(), span),
            method,
            ...params
          );
        } catch (err) {
          span.recordException(err);
          span.setStatus({
            code: api.SpanStatusCode.ERROR,
            message: err.message,
          });
          throw err;
        } finally {
          span.end();
        }

Test it out!
Docs: https://open-telemetry.github.io/opentelemetry-js/classes/_opentelemetry_context_async_hooks.asynchookscontextmanager.html#with

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks! it looks much better now.

};
return newHandler as T;
}
Expand Down Expand Up @@ -386,10 +396,19 @@ export class HapiInstrumentation extends InstrumentationBase {
const span = instrumentation.tracer.startSpan(metadata.name, {
attributes: metadata.attributes,
});
const res = await oldHandler(request, h, err);
span.end();

return res;
try {
const res = await oldHandler(request, h, err);
return res;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't need the assignment nor await here. Just return oldHandler(...);

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

removed the unneeded assignment.
as for the await, it is needed as catch won't work on promises that are not awaited, and I also need to wait to close the span after the action was completed.
maybe i should add a test that includes an async handler?
Also, there is a handy eslint rule that covers that https://github.com/typescript-eslint/typescript-eslint/blob/master/packages/eslint-plugin/docs/rules/return-await.md.

} catch (err) {
span.recordException(err);
span.setStatus({
code: api.SpanStatusCode.ERROR,
message: err.message,
});
throw err;
} finally {
span.end();
}
};
if (route.options?.handler) {
route.options.handler = newHandler;
Expand Down
Expand Up @@ -14,7 +14,7 @@
* limitations under the License.
*/

import { context, trace } from '@opentelemetry/api';
import { context, SpanStatusCode, trace } from '@opentelemetry/api';
import { NodeTracerProvider } from '@opentelemetry/node';
import { AsyncHooksContextManager } from '@opentelemetry/context-async-hooks';
import {
Expand Down Expand Up @@ -371,5 +371,41 @@ describe('Hapi Instrumentation - Server.Ext Tests', () => {
assert.strictEqual(res.statusCode, 200);
assert.deepStrictEqual(memoryExporter.getFinishedSpans().length, 0);
});

it('should end span and record the error if an error is thrown in ext', async () => {
const errorMessage = 'error';
const rootSpan = tracer.startSpan('rootSpan');
const extension: hapi.ServerExtEventsRequestObject = {
type: 'onRequest',
method: async (request, h, err) => {
throw new Error(errorMessage);
},
};
server.ext(extension);
await server.start();
assert.strictEqual(memoryExporter.getFinishedSpans().length, 0);

await context.with(
trace.setSpan(context.active(), rootSpan),
async () => {
const res = await server.inject({
method: 'GET',
url: '/test',
});
assert.strictEqual(res.statusCode, 500);

rootSpan.end();
assert.deepStrictEqual(memoryExporter.getFinishedSpans().length, 2);
const extHandlerSpan = memoryExporter
.getFinishedSpans()
.find(span => span.name === 'ext - onRequest');

assert.notStrictEqual(extHandlerSpan, undefined);
assert.strictEqual(extHandlerSpan?.events[0].name, 'exception');
assert.strictEqual(extHandlerSpan.status.code, SpanStatusCode.ERROR);
assert.strictEqual(extHandlerSpan.status.message, errorMessage);
}
);
});
});
});
Expand Up @@ -14,7 +14,7 @@
* limitations under the License.
*/

import { context, trace } from '@opentelemetry/api';
import { context, trace, SpanStatusCode } from '@opentelemetry/api';
import { RPCType, setRPCMetadata } from '@opentelemetry/core';
import { SemanticAttributes } from '@opentelemetry/semantic-conventions';
import { NodeTracerProvider } from '@opentelemetry/node';
Expand Down Expand Up @@ -364,6 +364,46 @@ describe('Hapi Instrumentation - Core Tests', () => {
}
);
});

it('should end span and record the error if an error is thrown in route handler', async () => {
const errorMessage = 'error';
const rootSpan = tracer.startSpan('rootSpan', {});
server.route({
method: 'GET',
path: '/users/{userId}',
handler: (request, h) => {
throw new Error(errorMessage);
},
});

await server.start();
assert.strictEqual(memoryExporter.getFinishedSpans().length, 0);
const rpcMetadata = { type: RPCType.HTTP, span: rootSpan };
await context.with(
setRPCMetadata(trace.setSpan(context.active(), rootSpan), rpcMetadata),
async () => {
const res = await server.inject({
method: 'GET',
url: '/users/1',
});
assert.strictEqual(res.statusCode, 500);

rootSpan.end();
assert.deepStrictEqual(memoryExporter.getFinishedSpans().length, 2);

const requestHandlerSpan = memoryExporter
.getFinishedSpans()
.find(span => span.name === 'route - /users/{userId}');
assert.notStrictEqual(requestHandlerSpan, undefined);
assert.strictEqual(requestHandlerSpan?.events[0].name, 'exception');
assert.strictEqual(
requestHandlerSpan.status.code,
SpanStatusCode.ERROR
);
assert.strictEqual(requestHandlerSpan.status.message, errorMessage);
}
);
});
});

describe('Disabling Hapi instrumentation', () => {
Expand Down