feat(instrumentation-express): Use router path in router span names

[onurtemizkan]

Related: getsentry/sentry-javascript#12103

Which problem is this PR solving?

• router spans are falling back to / as their span name in the current implementation. (Issue: Express instrumentation does not properly handle router usage #1993)
• requestHandler spans are not showing the full route in their span name when nested routers are used. (This is not fixing exactly but it is related to fix wrong rpcMetadata.route value when route.use(<middleware>) handle nested router #1613)

Short description of the changes

• This PR adds a new utility (getRouterPath) to recursively search the (possibly nested) parameterised router path when getting the layer metadata. This only affects the span name, not the http.route attribute of the span. http.route is still showing the mount path. (Active discussion on this: Express instrumentation does not properly handle router usage #1993 (comment))

• Uses route primarily to assign the requestHandler span name instead of layerPath. layerPath does not represent the full path, only the path of the last matching router when nested routers are used.

So if we have a nested router setup like:

const userRouter = express.Router();
const postsRouter = express.Router();

postsRouter.get('/:postId', (req, res, next) => {
  // ...
});

userRouter.get('/api/user/:id', (req, res, next) => {
  // ...
});

userRouter.use('/api/user/:id/posts', postsRouter);

app.use(userRouter);

The new behaviour is as below:

Current Implementation	New Implementation
router - /	router - /api/user/:id
router - /api/user/:id/posts	router - /:postId
requestHandler - /:postId	requestHandler - /api/user/:id/posts/:postId

[codecov]

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 90.75%. Comparing base (dfb2dff) to head (d5ba274).
Report is 242 commits behind head on main.

Additional details and impacted files

@@            Coverage Diff             @@
##             main    #2319      +/-   ##
==========================================
- Coverage   90.97%   90.75%   -0.23%     
==========================================
  Files         146      156      +10     
  Lines        7492     7700     +208     
  Branches     1502     1583      +81     
==========================================
+ Hits         6816     6988     +172     
- Misses        676      712      +36     

Files with missing lines	Coverage Δ
...try-instrumentation-express/src/instrumentation.ts	98.58% <100.00%> (-1.42%)	⬇️
...etry-instrumentation-express/src/internal-types.ts	100.00% <ø> (ø)
...opentelemetry-instrumentation-express/src/utils.ts	98.46% <100.00%> (+0.84%)	⬆️

... and 74 files with indirect coverage changes

[JamieDanielson]

Thank you for your work on this! Overall I like the idea of this and it seems to resolve the issue of span names from basic router usage as I had flagged in the issue, properly renaming -router - / to -router - /post/:id in the router.get usage.

What I'm currently stuck on is the nested router use case. The second router span in this PR is rewritten to router - /:postId, which matches the postsRouter.get('/:postId'). The current (on main) implementation is actually using the path from userRouter.use('/api/user/:id/posts'), and is fully excluding the postsRouter.get('/:postId'). So the table is a bit inaccurate there (it's not currently router -/), but I am not sure of what we should expect for that second router span. Should it be router - /:postId or should it be router - /api/user/:id/posts/:postId?

Current Implementation	New Implementation
router - /	router - /api/user/:id
router - / router - /api/user/:id/posts	router - /:postId
requestHandler - /:postId	requestHandler - /api/user/:id/posts/:postId

[onurtemizkan]

So the table is a bit inaccurate there (it's not currently router -/)

@JamieDanielson, yes you're right. Thanks for pointing that out.

not sure of what we should expect for that second router span. Should it be router - /:postId or should it be router - /api/user/:id/posts/:postId

/:postId actually is the lower-level router. So IMHO it feels more accurate to have it as the router span name. We get the full path from the requestHandler span in this case.

[JamieDanielson]

This is titled as a fix, but it could perhaps be considered a feature as it properly implements the router instrumentation 😁 🤷 . I lean toward feature because it is changing span names and is more or less implementing something that didn't properly exist before. What do you think about a title like "feat(instrumentation-express):Use router path in router span names"?

[andreiborza]

@JamieDanielson we're happy with the rename, feel free to edit.

[JamieDanielson]

I want to hold onto this for a bit longer until this other PR #2408 is merged that fixes the instrumentation of http.get and changes the output of the ESM spans. It's going to require a few more changes to the ESM tests but they will make more sense now with the client and server spans.

After that PR merges and we update this branch we'll see the ESM tests fail. We'll just need to update the ESM tests here and then this will be good to go 🚀

[JamieDanielson]

I want to hold onto this for a bit longer until this other PR #2408 is merged that fixes the instrumentation of http.get and changes the output of the ESM spans. It's going to require a few more changes to the ESM tests but they will make more sense now with the client and server spans.

After that PR merges and we update this branch we'll see the ESM tests fail. We'll just need to update the ESM tests here and then this will be good to go 🚀

I've merged in main and updated the test to use otlpSpanKind. Once tests pass we can merge.

[JamieDanielson]

The failed tests may be intermittent and unrelated to this. I created #2436 to track but after some re-running they are working. Hope to be able to merge soon!

[biuboombiuboom]

em.....if layerPath is undefined, the router span name still does not contain the full route
utils.ts>storLayerPath

           if (value === undefined) return;
           (request[_LAYERS_STORE_PROPERTY] as string[]).push(value);

instrumentation.ts line 276-277, pop layerStore does`t check layerPath

            if (!(req.route && isError)) {
              (req[_LAYERS_STORE_PROPERTY] as string[]).pop();
            }

test code

it('should full route with route use(<middleware>)', async () => {
    const rootSpan = tracer.startSpan('rootSpan');
    const customMiddleware: express.RequestHandler = (req, res, next) => {
      for (let i = 0; i < 1000000; i++) {
        continue;
      }
      return next();
    };
    let finishListenerCount: number | undefined;
    let rpcMetadata: RPCMetadata | undefined;
    const httpServer = await serverWithMiddleware(tracer, rootSpan, app => {
      app.use(express.json());
      app.use((req, res, next) => {
        rpcMetadata = getRPCMetadata(context.active());
        res.on('finish', () => {
          finishListenerCount = res.listenerCount('finish');
        });
        next();
      });
      const router = express.Router();
      app.use('/users', router);
      router.get('/:userId', (req, res) => {
        res.status(200).end('user-' + req.params.userId);
      });
      router.use(customMiddleware);
      const bookRouter = express.Router({ mergeParams: true });
      router.use('/:userId/books', bookRouter);
      bookRouter.get('/:bookId', (req, res) => {
        setImmediate(() => {
          res.status(200).end('book-' + req.params.bookId);
        });
      });
    });
   let port = httpServer.port;
    assert.strictEqual(memoryExporter.getFinishedSpans().length, 0);
    await context.with(
      trace.setSpan(context.active(), rootSpan),
      async () => {
        const response = await httpRequest.get(
          `http://localhost:${port}/users/1/books/2`
        );
        assert.strictEqual(response, 'book-2');
        rootSpan.end();
        assert.strictEqual(finishListenerCount, 2);
        assert.notStrictEqual(
          memoryExporter
            .getFinishedSpans()
            .find(span => span.name.includes('customMiddleware')),
          undefined
        );
        assert.notStrictEqual(
          memoryExporter
            .getFinishedSpans()
            .find(span => span.name.includes('jsonParser')),
          undefined
        );
        const requestHandlerSpan = memoryExporter
        .getFinishedSpans()
        .find(span => span.name.includes('request handler'));
      assert.notStrictEqual(requestHandlerSpan, undefined);
        assert.notStrictEqual(requestHandlerSpan, undefined);
        assert.strictEqual(
          requestHandlerSpan?.attributes['http.route'],
          '/users/:userId/books/:bookId'
        );
   
        assert.strictEqual(
          rpcMetadata?.route,
          '/users/:userId/books/:bookId'
        );
      }
    );