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

ServerTracingFilter does not account for traces / timing in pre match filters #130

Open
billoneil opened this issue May 19, 2019 · 9 comments

Comments

@billoneil
Copy link

Currently ServerTracingFilter is wired up using a dynamic feature which makes it a post-matching filter. This means any processing done in pre-match filters is currently being excluded from traces.

Would it be possible to make this work as a pre match filter instead?

@pavolloffay
Copy link
Collaborator

pavolloffay commented May 20, 2019

hi @billoneil, could you please describe what use-case, why do you need to initiate tracing in pre-match?

There has been some discussion here #13. I don't remember why we didn't go forward.

@billoneil
Copy link
Author

I noticed this when migrating from one of our APM solutions to another. We have ~3 endpoints which are polled and have significantly higher throughput than all other endpoints in our system. In the new APM they are showing to take ~30% the response time as the old one and I tracked it down to being related to pre-matching filters. Even though the pre match filters only take ~3-5ms that ends up being ~60% of the request time.

I can look into seeing if our filters actually require being pre-match we might be able to switch them. Thought I would mention it here in case there was an easy way to switch this to a pre-match filter.

@Fox32
Copy link

Fox32 commented May 24, 2019

In our first use case, requests get filtered before the dynamic feature is tracing them (e.g. by authorization). Therefore we can't see traces/spans for them. Maybe there should be two spans, an outer one for incoming http requests and a later one after the requests got matched (jax-rs specific)?

In another case we make a call to a different component during pre-match (Open Policy Agent, also authorization) which we would like to trace as well, but it occurs before the trace is extracted.

I guess #74 made it possible to extract the trace and add additional instrumentation before the jax-rs instrumentation. Right now my plan is to add an own filter/extract step before the jax-rs instrumentation in our code, but I guess that would be useful for a lot of people.

@pavolloffay
Copy link
Collaborator

I don't mind switching to pre-match if we keep the current behavior/offer the same features. PRs are of course welcome.

#74 made it possible to integrate with servlet filters which can initiate tracing before jax-rs kicks in.

@Fox32
Copy link

Fox32 commented May 28, 2019

I don't think that @PreMatch would keep the old behavior, as you don't have the matched classes/methods during pre-match. One would need a pre match and a post match filter.

@pavolloffay
Copy link
Collaborator

If it can be configurable I am fine with it. There is a builder pattern where these things could be specified.

@billoneil
Copy link
Author

@Fox32 any suggestions on what that flow might look like? I'm just learning open tracing now so I'm not familiar with what can be done when. Is it possible to start the root trace in a pre-match filter then tag / name it with the post-match filter?

@Fox32
Copy link

Fox32 commented Jun 7, 2019

Is it possible to start the root trace in a pre-match filter then tag / name it with the post-match filter?

@billoneil First I thought that this wouldn't work, but then I tried it:

      Span span = GlobalTracer.get().buildSpan("Work").start();

      try (Scope ignored = GlobalTracer.get().scopeManager().activate(span)) {
        // Work
      } finally {
        span.setOperationName("Test");
        span.finish();
      }

I'm surprised, this works as expected. My first idea was to create two spans, one that only has the HTTP method as an operation name and a second one that contains the operation (if available). But now we could start a span with the HTTP method as the operation name during pre match and later after matching fill it with the real operation name. If not matching is done (e.g. a filter exits early), we would still have a span with some useful information. I like that idea.

@Kanikakhetawat
Copy link

Kanikakhetawat commented Jul 26, 2021

We have a similar use case to trace the time and errors in other pre-match filters.

@Fox32 the current code should still work as is with just a new annotation of PreMatch filter and priority, though we would need to handle for cases when the resource class/method doesn't match.

@pavolloffay does the requirement and change look reasonable to you?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants