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

Activities were getting closed with incorrect duration #1432

Conversation

carlos-neto-maersk
Copy link

Context

While using @qhris (thank you 🙏 ) work before it was published, we started to notice a weird pattern for the metrics.
Our current setup has a .NET Framework ASP.NET application instrumented with OpenTelemetry dotnet client, and we needed to have the metrics tagged with route information, so that we are able to support grafana dashboards over it (we haven't found a way to do it over trace information). We are also using OTEL to feed the connected App Insights instance.

As soon as we packed and deployed the code, due to the high load the system is subjected to (10M+ requests/day) we noticed a saw tooth pattern on the reported graphs in AppInsights and Grafana.

Screenshot 2023-11-10 at 15 53 55
Screenshot 2023-11-10 at 15 54 20

As you can see on the above, we have several thousand requests being saved with a duration of ~1ms. We also have the following:
Screenshot 2023-11-14 at 15 00 41
Screenshot 2023-11-14 at 15 02 58
Sorry for the redacted services names.

Fixes #1431 .

Changes

I reverted ActivityHelper to 895a9c7.
Since this breaks the enrichment logic developed in #1407 (this was already address in #1425 ), I've added the duration computation logic into the HttpInMetricsListener (not the best place I know, but). I've tried to "import" most of the code from Activity, to have high precision.

Next steps

I would like to further improve the code and add unit tests, but to be clear my knowledge on this (ASP.NET lifecycle pipelines) is very limited to what Microsoft (still) has on their documentation pages, so I would request aid to understand the unit test case and to work on it.

For significant contributions please make sure you have completed the following items:

  • Appropriate CHANGELOG.md updated for non-trivial changes
  • Design discussion issue #
  • Changes in public API reviewed

@carlos-neto-maersk carlos-neto-maersk requested a review from a team as a code owner November 14, 2023 15:23
Copy link

linux-foundation-easycla bot commented Nov 14, 2023

CLA Signed

The committers listed above are authorized under a signed CLA.

  • ✅ login: carlos-neto-maersk / name: Carlos Neto (d4b2048)

…ation instead of activity durationCalculating the metrics duration on the metrics handler instead of stopping asp.net activity
Copy link
Member

@vishweshbankwar vishweshbankwar left a comment

Choose a reason for hiding this comment

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

@utpilla utpilla added the comp:instrumentation.aspnet Things related to OpenTelemetry.Instrumentation.AspNet label Nov 17, 2023
@qhris
Copy link
Contributor

qhris commented Nov 17, 2023

I believe moving aspNetActivity.Stop(); is a no go, and we need to find another way.

You can see why by setting options.ExportProcessorType = ExportProcessorType.Simple; (for OtlpExporterOptions).
Running it like this with the changes in this PR you'll see that a few span attributes will be missing:

  • http.status_code
  • http.route

They are missing because the span is exported before HttpInListener.OnStopActivity is run.

Copy link
Contributor

This PR was marked stale due to lack of activity. It will be closed in 7 days.

@github-actions github-actions bot added the Stale label Nov 25, 2023
Copy link
Contributor

github-actions bot commented Dec 3, 2023

Closed as inactive. Feel free to reopen if this PR is still being worked on.

@github-actions github-actions bot closed this Dec 3, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp:instrumentation.aspnet Things related to OpenTelemetry.Instrumentation.AspNet Stale
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Duration is not being counted for properly [.NET Framework 4.8 Metrics & Telemetry Module]
4 participants