apache / apache/pulsar-client-go
pulsar_client_consumer_processing_time_seconds metric records incorrect values
- Dominant language
- Go
- Stars
- 745
- Forks
- 389
- Avg merge
- 3d 20h
- Merged PRs (30d)
- 3
Description
#### Expected behavior
The `pulsar_client_consumer_processing_time_seconds` metric should contain observations of the time it takes a consumer to process messages.
#### Actual behavior
The observations are wrong. They have values of approximately 8.5e+09 (~269 years).
#### Steps to reproduce
Create a consumer, ack some messages, check the metrics. e.g.
```
func main() {
http.Handle("/metrics", promhttp.Handler())
go http.ListenAndServe(":9090", nil)
client, err := pulsar.NewClient(pulsar.ClientOptions{
URL: URL,
Authentication: pulsar.NewAuthenticationToken(TOKEN),
})
if err != nil {
panic(err)
}
defer client.Close()
consumer, err := client.Subscribe(pulsar.ConsumerOptions{
Topic: TOPIC,
Name: "test-consumer",
SubscriptionName: "test-subscription",
})
if err != nil {
panic(err)
}
msg, err := consumer.Receive(context.Background())
if err != nil {
panic(err)
}
err = consumer.Ack(msg)
if err != nil {
panic(err)
}
time.Sleep(time.Hour)
}
```
produces
```
# HELP pulsar_client_consumer_processing_time_seconds Time it takes for application to process messages
# TYPE pulsar_client_consumer_processing_time_seconds histogram
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.0005"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.001"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.005"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.01"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.025"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.05"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.1"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.25"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="0.5"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="1"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="2.5"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="5"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="10"} 0
pulsar_client_consumer_processing_time_seconds_bucket{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN",le="+Inf"} 1
pulsar_client_consumer_processing_time_seconds_sum{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN"} 8.500242974069234e+09
pulsar_client_consumer_processing_time_seconds_count{client="go",pulsar_namespace="HIDDEN",pulsar_tenant="HIDDEN"}
```
#### System configuration
**Pulsar version**: 2.10
**Pulsar client version**:v0.11.1
Contributor guide
Research direction
Start by reproducing the issue with the provided consumer Receive/Ack example and exposing metrics through promhttp.Handler. Search the client for pulsar_client_consumer_processing_time_seconds and the acknowledgement path, then verify that the histogram observes processing time in seconds rather than a large timestamp-like value. Done means the reported value matches the time taken to process messages.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- go, prometheus
- Domain
- observability-sre
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Clearly specified
- Newbie friendliness
- 45/100