Don't work nginx_http_response_time_seconds in new version

[xelatirdan]

Describe the bug:

Hello, after update to new container metric nginx_http_response_time_seconds is disappeared.
When I fall back to old container all work as expected.

To Reproduce:

# docker run -d --rm --name prometheus-nginxlog-exporter --net=host -v /var/log/nginx:/mnt/nginxlogs quay.io/martinhelmich/prometheus-nginxlog-exporter:latest -format="\$remote_addr - \$remote_user [\$time_local] \"\$request\" \$status \$body_bytes_sent \"\$http_referer\" \"\$http_user_agent\" \"\$http_x_forwarded_for\" \$request_time \$upstream_response_time" mnt/nginxlogs/access.log
# curl -q localhost:4040/metrics | grep 'nginx_http_response_time_seconds{'
...nothing

Expected behavior:

# curl -q localhost:4040/metrics | grep 'nginx_http_response_time_seconds{'
...
nginx_http_response_time_seconds{method="GET",status="200",quantile="0.5"} 0
nginx_http_response_time_seconds{method="GET",status="200",quantile="0.9"} 0.048
nginx_http_response_time_seconds{method="GET",status="200",quantile="0.99"} 10.645
nginx_http_response_time_seconds{method="GET",status="206",quantile="0.5"} 0
nginx_http_response_time_seconds{method="GET",status="206",quantile="0.9"} 0.004
nginx_http_response_time_seconds{method="GET",status="206",quantile="0.99"} 0.013
nginx_http_response_time_seconds{method="GET",status="301",quantile="0.5"} 0.002
nginx_http_response_time_seconds{method="GET",status="301",quantile="0.9"} 0.003
...

Example log file:

# docker logs prometheus-nginxlog-exporter
using configuration {Listen:{Port:4040 Address:0.0.0.0 MetricsEndpoint:/metrics} Consul:{Enable:false Address: Datacenter: Scheme: Token: Service:{ID: Name: Address: Tags:[]}} Namespaces:[{Name:nginx SourceFiles:[] SourceData:{Files:[mnt/nginxlogs/access.log] Syslog:<nil>} Format:$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $request_time $upstream_response_time Labels:map[] RelabelConfigs:[] HistogramBuckets:[] OrderedLabelNames:[] OrderedLabelValues:[]}] EnableExperimentalFeatures:false EnableExperimentalFeaturesOld:false}
starting listener for namespace nginx
running HTTP server on address 0.0.0.0:4040, serving metrics at /metrics
2020/05/04 15:25:33 Seeked mnt/nginxlogs/access.log - &{Offset:0 Whence:2}
2020/05/04 21:00:52 Re-opening moved/deleted file mnt/nginxlogs/access.log ...
2020/05/04 21:00:52 Successfully reopened mnt/nginxlogs/access.log

Environment:

• Exporter version: v1.6.2
• OS (e.g. from /etc/os-release): Debian 10
• Deployment method (e.g. Docker image, deb/rpm package, self-compiled, ...): Docker image

[martin-helmich]

Thanks for the report. From which version did you upgrade?

FWIW, since #54, the exporter only reads the log file from the end of the file (because otherwise, older logs will be correlated not with their actual timestamps, but with the exporter's start time -- and also, Prometheus' rate function goes haywire from that). Maybe that's the issue, here? Do metrics appear when new log lines have been written to the file after the exporter has started?

[tommynd]

I've also have this problem. I used a very old version v1.2.0 and used the latest version on another instance. The http_response_time_seconds is missing. I downgraded to version v1.3.0 and it worked again, without changes to the log format.

Looks like this behaviour is since v1.4.0.

I also deployed with a docker image.

[leobasilio]

I'm a new user. Just pulled the v1 tagged image, which seems to be v1.7.0, and I can tell nginx_http_response_time_seconds is there. Actually there are both a histogram and a summary metric, so we have:

• nginx_http_response_time_seconds_hist_bucket
• nginx_http_response_time_seconds_hist_sum
• nginx_http_response_time_seconds_hist_count
• nginx_http_response_time_seconds_sum
• nginx_http_response_time_seconds_count

[Aderks]

Using latest v1.7.0, can also confirm there is no: nginx_http_response_time_seconds

Can only see nginx_http_response_time_seconds_... sum, count, hist_bucket, hist_sum, hist_count

[martin-helmich]

Found it -- newer versions of the prometheus instrumentation library require summary quantiles to be configured explicitly:

https://github.com/prometheus/client_golang/blob/03575cad4e55adb37a5396afa7cc0eec43526740/prometheus/summary.go#L116-L121

#136 contains a fix for this issue. Thanks for the report and your patience.

[Aderks]

Fix looks good on 1.7.1! Cheers