Metric - Error in collected metric `http_server_duration` #737

julianocosta89 · 2023-02-09T08:55:38Z

Bug Report

Which version of the demo you are using?
6af2bdc.

Symptom

A clear and concise description of what the bug is.

What is the expected behavior?
I expect the sample to run without any errors.

What is the actual behavior?

After starting the sample, I started getting the following error on the OTel collector logs:

otel-col                 | * collected metric http_server_duration label:<name:"container_id" value:"354b4b881bf8956b0483f2231f348cd99f4a56e087617808e1ff88ac435400d2" > label:<name:"http_flavor" value:"HTTP/2" > label:<name:"http_host" value:"cartservice:7070" > label:<name:"http_method" value:"POST" > label:<name:"http_scheme" value:"http" > label:<name:"http_status_code" value:"200" > label:<name:"http_target" value:"/hipstershop.CartService/GetCart" > label:<name:"job" value:"opentelemetry-demo/cartservice" > label:<name:"service_name" value:"cartservice" > label:<name:"service_namespace" value:"opentelemetry-demo" > label:<name:"telemetry_sdk_language" value:"dotnet" > label:<name:"telemetry_sdk_name" value:"opentelemetry" > label:<name:"telemetry_sdk_version" value:"1.4.0.665" > histogram:<sample_count:615 sample_sum:689.5118000000004 bucket:<cumulative_count:0 upper_bound:0 > bucket:<cumulative_count:613 upper_bound:5 > bucket:<cumulative_count:614 upper_bound:10 > bucket:<cumulative_count:614 upper_bound:25 > bucket:<cumulative_count:614 upper_bound:50 > bucket:<cumulative_count:614 upper_bound:75 > bucket:<cumulative_count:614 upper_bound:100 > bucket:<cumulative_count:615 upper_bound:250 > bucket:<cumulative_count:615 upper_bound:500 > bucket:<cumulative_count:615 upper_bound:750 > bucket:<cumulative_count:615 upper_bound:1000 > bucket:<cumulative_count:615 upper_bound:2500 > bucket:<cumulative_count:615 upper_bound:5000 > bucket:<cumulative_count:615 upper_bound:7500 > bucket:<cumulative_count:615 upper_bound:10000 > >  has help "measures the duration of the inbound HTTP request" but should have "measures the duration of the inbound HTTP requests"
otel-col                 |      {"kind": "exporter", "data_type": "metrics", "name": "prometheus"}
otel-col                 | github.com/open-telemetry/opentelemetry-collector-contrib/exporter/prometheusexporter.(*promLogger).Println
otel-col                 |      github.com/open-telemetry/opentelemetry-collector-contrib/exporter/[email protected]/log.go:34
otel-col                 | github.com/prometheus/client_golang/prometheus/promhttp.HandlerForTransactional.func1
otel-col                 |      github.com/prometheus/[email protected]/prometheus/promhttp/http.go:139
otel-col                 | net/http.HandlerFunc.ServeHTTP
otel-col                 |      net/http/server.go:2109
otel-col                 | net/http.(*ServeMux).ServeHTTP
otel-col                 |      net/http/server.go:2487
otel-col                 | go.opentelemetry.io/collector/config/confighttp.(*decompressor).wrap.func1
otel-col                 |      go.opentelemetry.io/[email protected]/config/confighttp/compression.go:162
otel-col                 | net/http.HandlerFunc.ServeHTTP
otel-col                 |      net/http/server.go:2109
otel-col                 | go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*Handler).ServeHTTP
otel-col                 |      go.opentelemetry.io/contrib/instrumentation/net/http/[email protected]/handler.go:210
otel-col                 | go.opentelemetry.io/collector/config/confighttp.(*clientInfoHandler).ServeHTTP
otel-col                 |      go.opentelemetry.io/[email protected]/config/confighttp/clientinfohandler.go:39
otel-col                 | net/http.serverHandler.ServeHTTP
otel-col                 |      net/http/server.go:2947
otel-col                 | net/http.(*conn).serve
otel-col                 |      net/http/server.go:1991

Reproduce

Clone the repo and simply run:

docker compose up

We will close this issue if:

The steps you provided are complex.
If we can not reproduce the behavior you're reporting.

Additional Context

The app runs normally, but from the logs it seems that some metrics are not being sent to Prometheus.

The text was updated successfully, but these errors were encountered:

austinlparker · 2023-02-09T15:20:41Z

Hm, this seems like a mismatch between metrics somehow. Do we have the same metric in two places with mismatched help?

austinlparker · 2023-02-09T15:53:00Z

Interesting, that metric seems to have changed. At head...

# TYPE http_server_duration histogram
http_server_duration_bucket{http_flavor="HTTP/2",http_host="cartservice:7070",http_method="POST",http_scheme="http",http_status_code="200",http_target="/hipstershop.CartService/AddItem",job="opentelemetry-demo/cartservice",service_name="cartservice",service_namespace="opentelemetry-demo",telemetry_sdk_language="dotnet",telemetry_sdk_name="opentelemetry",telemetry_sdk_version="1.4.0.665",le="0"} 0

1.3.0

# HELP http_server_duration measures the duration of the inbound HTTP requests
# TYPE http_server_duration histogram
http_server_duration_bucket{container_id="8d004e7bce6343dfc65a4f5d7a562750588b7966e8ed4b05275e03aaac1c760d",host_arch="arm64",host_name="8d004e7bce63",http_flavor="1.1",http_method="GET",http_scheme="http",http_status_code="200",job="opentelemetry-demo/frontend",net_host_name="frontend",net_host_port="8080",os_type="linux",os_version="5.15.49-linuxkit",process_command="/app/server.js",process_command_line="/usr/local/bin/node /app/server.js",process_executable_name="node",process_pid="17",process_runtime_description="Node.js",process_runtime_name="nodejs",process_runtime_version="18.14.0",service_name="frontend",service_namespace="opentelemetry-demo",le="0"} 0

However, I think what's happening is that these metrics are in head and 1.3, but what's happening is that they're racing each other. The problem is, the #HELP text differs between them (which I believe is the OTLP metric description), which causes the prometheus exporter to not merge them correctly, but whichever one gets scraped + reported first is the one that 'wins' and prometheus won't overwrite what's already there?

austinlparker · 2023-02-09T16:56:35Z

Keeping this open as we'll need to take the release from .NET which fixes it upstream.

puckpuck · 2023-03-04T03:59:27Z

I tried taking the latest 1.4.0/1.0.0-rc9.14 from the .NET SDKs and still got the error. This PR should fix it. I will test it again after it's released.

cartersocha · 2023-03-31T21:34:06Z

Looks like we need to manually request a release. open-telemetry/opentelemetry-dotnet-contrib#1063 (comment)

@puckpuck would our ask be to update this to rc9.9?

https://github.com/open-telemetry/opentelemetry-dotnet-contrib/releases/tag/Instrumentation.AspNet.TelemetryHttpModule-1.0.0-rc9.8

puckpuck · 2023-04-01T03:21:49Z

I worked with @martinjt on this ... and it turns out I was barking up the wrong tree and I misunderstood how .NET instrumentation packages were done 🤦

We still see this error because JS also had the same incorrect description that the .NET SDK had. I have this PR in the JS repo to address this.

log entry from collector

otel-col  | * collected metric http_server_duration label:<name:"container_id" value:"e7414d44db0e8b8029644b59a47717a325a6c420f62dc08b293dc30c4b750c71" > label:<name:"host_arch" value:"arm64" > label:<name:"host_name" value:"e7414d44db0e" > label:<name:"http_flavor" value:"1.1" > label:<name:"http_method" value:"GET" > label:<name:"http_scheme" value:"http" > label:<name:"http_status_code" value:"200" > label:<name:"job" value:"opentelemetry-demo/frontend" > label:<name:"net_host_name" value:"frontend" > label:<name:"net_host_port" value:"8080" > label:<name:"os_type" value:"linux" > label:<name:"os_version" value:"5.15.49-linuxkit" > label:<name:"process_command" value:"/app/server.js" > label:<name:"process_command_line" value:"/usr/local/bin/node /app/server.js" > label:<name:"process_executable_name" value:"node" > label:<name:"process_pid" value:"16" > label:<name:"process_runtime_description" value:"Node.js" > label:<name:"process_runtime_name" value:"nodejs" > label:<name:"process_runtime_version" value:"18.15.0" > label:<name:"service_name" value:"frontend" > label:<name:"service_namespace" value:"opentelemetry-demo" > label:<name:"telemetry_sdk_language" value:"nodejs" > label:<name:"telemetry_sdk_name" value:"opentelemetry" > label:<name:"telemetry_sdk_version" value:"1.10.1" > histogram:<sample_count:122 sample_sum:3952 bucket:<cumulative_count:0 upper_bound:0 > bucket:<cumulative_count:19 upper_bound:5 > bucket:<cumulative_count:46 upper_bound:10 > bucket:<cumulative_count:103 upper_bound:25 > bucket:<cumulative_count:115 upper_bound:50 > bucket:<cumulative_count:116 upper_bound:75 > bucket:<cumulative_count:116 upper_bound:100 > bucket:<cumulative_count:118 upper_bound:250 > bucket:<cumulative_count:118 upper_bound:500 > bucket:<cumulative_count:122 upper_bound:1000 > >  has help "measures the duration of the inbound HTTP requests" but should have "Measures the duration of inbound HTTP requests."

austinlparker · 2023-04-04T13:51:39Z

The JS PR to fix this was merged (open-telemetry/opentelemetry-js#3710)

julianocosta89 · 2023-04-04T14:27:50Z

we just need a new release now 🤞🏽

puckpuck · 2023-08-04T04:18:55Z

I believe this is all resolved now, and we can close this issue.

julianocosta89 added the bug Something isn't working label Feb 9, 2023

austinlparker mentioned this issue Feb 9, 2023

HTTP Server Duration Histogram description does not follow specification open-telemetry/opentelemetry-dotnet#4169

Closed

jlawrienyt mentioned this issue Feb 9, 2023

Ensure all http.server.duration metrics have the same description #738

Merged

2 tasks

austinlparker closed this as completed in #738 Feb 9, 2023

austinlparker reopened this Feb 9, 2023

puckpuck mentioned this issue Mar 4, 2023

[Instrumentation.AspNet] fix metric description open-telemetry/opentelemetry-dotnet-contrib#1063

Merged

3 tasks

julianocosta89 added the v1.4 label Mar 7, 2023

julianocosta89 mentioned this issue Mar 7, 2023

Update .NET SDK to fix metric description #774

Closed

puckpuck mentioned this issue Apr 1, 2023

fix(instrumentation-http): use semantic convention metric descriptions open-telemetry/opentelemetry-js#3710

Merged

4 tasks

julianocosta89 closed this as completed Aug 5, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Metric - Error in collected metric `http_server_duration` #737

Metric - Error in collected metric `http_server_duration` #737

julianocosta89 commented Feb 9, 2023

austinlparker commented Feb 9, 2023

austinlparker commented Feb 9, 2023

austinlparker commented Feb 9, 2023

puckpuck commented Mar 4, 2023

cartersocha commented Mar 31, 2023

puckpuck commented Apr 1, 2023

austinlparker commented Apr 4, 2023

julianocosta89 commented Apr 4, 2023

puckpuck commented Aug 4, 2023

Metric - Error in collected metric http_server_duration #737

Metric - Error in collected metric http_server_duration #737

Comments

julianocosta89 commented Feb 9, 2023

Bug Report

Symptom

Reproduce

Additional Context

austinlparker commented Feb 9, 2023

austinlparker commented Feb 9, 2023

austinlparker commented Feb 9, 2023

puckpuck commented Mar 4, 2023

cartersocha commented Mar 31, 2023

puckpuck commented Apr 1, 2023

austinlparker commented Apr 4, 2023

julianocosta89 commented Apr 4, 2023

puckpuck commented Aug 4, 2023

Metric - Error in collected metric `http_server_duration` #737

Metric - Error in collected metric `http_server_duration` #737