Configure "nginx_http_response_time_seconds" with correct quantiles (#…

…136)

features/response_times.feature

@@ -8,7 +8,7 @@ Feature: Upstream response times are summarized
       """
     Then the exporter should report value 10 for metric nginx_http_upstream_time_seconds{method="GET",status="200",quantile="0.5"}
 
-  Scenario: .5 quantile is computed
+  Scenario: .5 quantile of upstream time is computed
     Given a running exporter listening on "access.log" with upstream-time format
     When the following HTTP request is logged to "access.log"
       """
@@ -18,3 +18,14 @@ Feature: Upstream response times are summarized
       172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 40
       """
     Then the exporter should report value 20 for metric nginx_http_upstream_time_seconds{method="GET",status="200",quantile="0.5"}
+
+  Scenario: .5 quantile of response time is computed
+    Given a running exporter listening on "access.log" with request-time format
+    When the following HTTP request is logged to "access.log"
+      """
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 10
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 20
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 30
+      172.17.0.1 - - [23/Jun/2016:16:04:20 +0000] "GET / HTTP/1.1" 200 612 "-" "curl/7.29.0" "-" 40
+      """
+    Then the exporter should report value 20 for metric nginx_http_response_time_seconds{method="GET",status="200",quantile="0.5"}

features/steps/steps.py

@@ -1,12 +1,14 @@
-from behave import *
+import logging
 import subprocess
 import time
+
 import requests
-import logging
+from behave import *
 
 formats = {
     "default": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for"',
-    "upstream-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $upstream_response_time'
+    "upstream-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $upstream_response_time',
+    "request-time": '$remote_addr - $remote_user [$time_local] "$request" $status $body_bytes_sent "$http_referer" "$http_user_agent" "$http_x_forwarded_for" $request_time'
 }
 
 bin_name = './prometheus-nginxlog-exporter'
@@ -20,7 +22,8 @@ def run_exporter_impl(context, filename):
     time.sleep(.5)
 
     if p.returncode is not None:
-        raise Exception('exporter exited too soon with exit code %d' % p.returncode)
+        raise Exception(
+            'exporter exited too soon with exit code %d' % p.returncode)
 
     context.process = p
 
@@ -33,21 +36,25 @@ def run_exporter_impl(context, filename, format):
     time.sleep(.5)
 
     if p.returncode is not None:
-        raise Exception('exporter exited too soon with exit code %d' % p.returncode)
+        raise Exception(
+            'exporter exited too soon with exit code %d' % p.returncode)
 
     context.process = p
 
+
 @given(u'a running exporter listening with configuration file "{config}"')
 def run_exporter_configfile_impl(context, config):
     p = subprocess.Popen([bin_name, '-config-file', 'features/%s' % config],
                          stdout=subprocess.PIPE, stderr=subprocess.PIPE)
     time.sleep(.5)
 
     if p.returncode is not None:
-        raise Exception('exporter exited too soon with exit code %d' % p.returncode)
+        raise Exception(
+            'exporter exited too soon with exit code %d' % p.returncode)
 
     context.process = p
 
+
 @when(u'the following HTTP request is logged to "{filename}"')
 @when(u'the following HTTP requests are logged to "{filename}"')
 def step_impl(context, filename):
@@ -61,19 +68,20 @@ def step_impl(context, filename):
 @when(u'the following HTTP requests are logged to syslog on port {port}')
 def step_impl(context, port):
     log = logging.getLogger('test')
-    log_handler = logging.handlers.SysLogHandler(("localhost", int(port)), logging.handlers.SysLogHandler.LOG_USER)
+    log_handler = logging.handlers.SysLogHandler(
+        ("localhost", int(port)), logging.handlers.SysLogHandler.LOG_USER)
     log.addHandler(log_handler)
 
     lines = [l for l in context.text.split("\n") if l != ""]
     for l in lines:
         log.info(l)
-    
+
     time.sleep(.5)
 
 
 @then(u'the exporter should report value {val} for metric {metric}')
 @then(u'the exporter should on "{endpoint}" report value {val} for metric {metric}')
-def step_impl(context, val, metric, endpoint = '/metrics'):
+def step_impl(context, val, metric, endpoint='/metrics'):
     endpoint = endpoint.lstrip("/")
     while True:
         try:
@@ -87,5 +95,5 @@ def step_impl(context, val, metric, endpoint = '/metrics'):
 
     lines = [l.strip("\n") for l in text.split("\n")]
     if not "%s %s" % (metric, val) in lines:
-        raise AssertionError('expected metric "%s" could not be verified. Actual metrics:\n%s' % (metric, text))
-
+        raise AssertionError(
+            'expected metric "%s" could not be verified. Actual metrics:\n%s' % (metric, text))

features/test-config-issue120.yaml

@@ -0,0 +1,10 @@
+enable_experimental: true
+
+listen:
+  port: 4040
+
+namespaces:
+  - name: test
+    format: "$remote_addr - $remote_user [$time_local] \"$request\" $status $body_bytes_sent \"$http_referer\" \"$http_user_agent\" $process_time $bytes_sent $request_length"
+    source_files:
+      - .behave-sandbox/access.log

main.go

@@ -133,6 +133,7 @@ func (m *Metrics) Init(cfg *config.NamespaceConfig) {
 		ConstLabels: cfg.NamespaceLabels,
 		Name:        "http_response_time_seconds",
 		Help:        "Time needed by NGINX to handle requests",
+		Objectives:  map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.99: 0.001},
 	}, labels)
 
 	m.responseSecondsHist = prometheus.NewHistogramVec(prometheus.HistogramOpts{