diff --git a/CHANGELOG.md b/CHANGELOG.md index 433a0e2df..38c04bd28 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -23,6 +23,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/). - Use new cpu.requests formula from Kubernetes. [PR #1595](https://github.com/3scale/APIcast/pull/1595) [THREESCALE-15465](https://redhat.atlassian.net/browse/THREESCALE-15465) - Fix batcher policy fails silently when configured with string values instead of integers. [PR #1597](https://github.com/3scale/APIcast/pull/1597) [THREESCALE-15547](https://redhat.atlassian.net/browse/THREESCALE-15547) - Unify timeout options between http clients library [PR #1600](https://github.com/3scale/APIcast/pull/1600) +- Set upstream metrics when sending request via proxy. [PR #1598](https://github.com/3scale/APIcast/pull/1598) [THREESCALE-10571](https://redhat.atlassian.net/browse/THREESCALE-15071) ### Added - Update APIcast schema manifest [PR #1550](https://github.com/3scale/APIcast/pull/1550) diff --git a/gateway/src/apicast/http_proxy.lua b/gateway/src/apicast/http_proxy.lua index 51bd617f8..771ba4138 100644 --- a/gateway/src/apicast/http_proxy.lua +++ b/gateway/src/apicast/http_proxy.lua @@ -55,6 +55,7 @@ local function forward_https_request(proxy_uri, uri, proxy_opts) local content_type = ngx_req_get_headers()["Content-Type"] local content_type_is_urlencoded = content_type and content_type:lower() == "application/x-www-form-urlencoded" local raw = false + local request_start = ngx.now() if http_methods_with_body[req_method] then @@ -165,6 +166,9 @@ local function forward_https_request(proxy_uri, uri, proxy_opts) res, err = httpc:request(request) if res then + ngx.ctx.proxy_upstream_status = res.status + ngx.ctx.proxy_upstream_response_time = ngx.now() - request_start + if opts.request_unbuffered and raw then err = send_response(sock, res, DEFAULT_CHUNKSIZE) if err then diff --git a/gateway/src/apicast/policy/nginx_metrics/nginx_metrics.lua b/gateway/src/apicast/policy/nginx_metrics/nginx_metrics.lua index 532d1a084..a8f5ea6bc 100644 --- a/gateway/src/apicast/policy/nginx_metrics/nginx_metrics.lua +++ b/gateway/src/apicast/policy/nginx_metrics/nginx_metrics.lua @@ -155,7 +155,9 @@ function _M.log(_, context) if context.service and extended_metrics then service = context.service end - upstream_metrics.report(ngx.var.upstream_status, ngx.var.upstream_response_time, service) + local upstream_status = ngx.var.upstream_status or ngx.ctx.proxy_upstream_status + local upstream_response_time = ngx.var.upstream_response_time or ngx.ctx.proxy_upstream_response_time + upstream_metrics.report(upstream_status, upstream_response_time, service) report_req_response_time(service) metrics_updater.inc(apicast_status_metric, status_map[ngx.status]) end diff --git a/spec/http_proxy_spec.lua b/spec/http_proxy_spec.lua index fe2b2b77f..3dbe10f8b 100644 --- a/spec/http_proxy_spec.lua +++ b/spec/http_proxy_spec.lua @@ -11,11 +11,11 @@ describe('http_proxy', function() local captured_request = nil - local function stub_resty_http_proxy() + local function stub_resty_http_proxy(response) local httpc = { } - local response = {} + response = response or {} stub(httpc, 'request', function() return response end) stub(httpc, 'proxy_response') stub(httpc, 'set_keepalive') @@ -29,11 +29,6 @@ describe('http_proxy', function() stub(http_writer, 'proxy_response') end - before_each(function() - stub_ngx_request() - stub_resty_http_proxy() - end) - describe('on https backend', function() local upstream = { uri = { @@ -46,10 +41,12 @@ describe('http_proxy', function() } before_each(function() + stub_ngx_request() stub(upstream, 'rewrite_request') end) it('terminates phase', function() + stub_resty_http_proxy() local http_proxy = require('apicast.http_proxy') http_proxy.request(upstream, proxy_uri) assert.spy(ngx.exit).was_called_with(ngx.OK) @@ -57,6 +54,7 @@ describe('http_proxy', function() it('handles nil upstream_connection_opts gracefully', function() captured_request = nil -- Reset captured request + stub_resty_http_proxy() local upstream = { uri = { @@ -81,6 +79,7 @@ describe('http_proxy', function() it('passes timeouts to proxy.new at top level', function() captured_request = nil -- Reset captured request + stub_resty_http_proxy() local upstream = { uri = { @@ -118,6 +117,15 @@ describe('http_proxy', function() captured_request.proxy_options.upstream_connection_opts, 'proxy_options should still contain upstream_connection_opts') end) + + it('stores upstream status and response time in ngx.ctx', function() + stub_resty_http_proxy({ status = 200 }) + ngx.ctx = {} + local http_proxy = require('apicast.http_proxy') + http_proxy.request(upstream, proxy_uri) + assert.equal(200, ngx.ctx.proxy_upstream_status) + assert.is_number(ngx.ctx.proxy_upstream_response_time) + end) end) end) end) diff --git a/spec/policy/nginx_metrics/nginx_metrics_spec.lua b/spec/policy/nginx_metrics/nginx_metrics_spec.lua new file mode 100644 index 000000000..d68b225d7 --- /dev/null +++ b/spec/policy/nginx_metrics/nginx_metrics_spec.lua @@ -0,0 +1,44 @@ +local nginx_metrics = require('apicast.policy.nginx_metrics.nginx_metrics') + +describe('nginx_metrics policy', function() + describe('.log', function() + local upstream_metrics + + before_each(function() + upstream_metrics = require('apicast.metrics.upstream') + stub(upstream_metrics, 'report') + + local metrics_updater = require('apicast.metrics.updater') + stub(metrics_updater, 'inc') + + ngx.status = 200 + end) + + it('uses ngx.var upstream values when present', function() + ngx.var = { upstream_status = '200', upstream_response_time = '0.5' } + ngx.ctx = { proxy_upstream_status = 502, proxy_upstream_response_time = 1.2 } + + nginx_metrics.log(nil, {}) + + assert.stub(upstream_metrics.report).was_called_with('200', '0.5', { id = "", system_name = "" }) + end) + + it('falls back to ngx.ctx values set by the http_proxy module when ngx.var ones are missing', function() + ngx.var = { upstream_status = nil, upstream_response_time = nil } + ngx.ctx = { proxy_upstream_status = 200, proxy_upstream_response_time = 0.75 } + + nginx_metrics.log(nil, {}) + + assert.stub(upstream_metrics.report).was_called_with(200, 0.75, { id = "", system_name = "" }) + end) + + it('reports nil when neither ngx.var nor ngx.ctx have upstream values', function() + ngx.var = { upstream_status = nil, upstream_response_time = nil } + ngx.ctx = {} + + nginx_metrics.log(nil, {}) + + assert.stub(upstream_metrics.report).was_called_with(nil, nil, { id = "", system_name = "" }) + end) + end) +end) diff --git a/t/prometheus-metrics.t b/t/prometheus-metrics.t index 9d6bbb8d5..8a02e61cc 100644 --- a/t/prometheus-metrics.t +++ b/t/prometheus-metrics.t @@ -2,6 +2,7 @@ use lib 't'; use Test::APIcast::Blackbox 'no_plan'; require("policies.pl"); +require("http_proxy.pl"); # The output varies between requests, so run only once repeat_each(1); @@ -492,3 +493,226 @@ qr/apicast_status\{status="404"\} 1/, ]] --- no_error_log [error] + + +=== TEST 9: HTTPS proxy reports upstream metrics via ngx.ctx fallback +When the request goes through the HTTPS proxy path, ngx.var.upstream_status is +not set by nginx. The http_proxy module populates ngx.ctx.proxy_upstream_status +and ngx.ctx.proxy_upstream_response_time, and the nginx_metrics policy falls +back to those values. Verify the upstream_status metric is reported. +--- env eval +( + "https_proxy" => $ENV{TEST_NGINX_HTTPS_PROXY}, + 'BACKEND_ENDPOINT_OVERRIDE' => "http://test_backend.lvh.me:$ENV{TEST_NGINX_SERVER_PORT}" +) +--- configuration random_port env +{ + "services": [ + { + "id": 42, + "backend_version": 1, + "backend_authentication_type": "service_token", + "backend_authentication_value": "token-value", + "proxy": { + "hosts": ["one"], + "api_backend": "https://test-upstream.lvh.me:$TEST_NGINX_RANDOM_PORT", + "proxy_rules": [ + { "pattern": "/", "http_method": "GET", "metric_system_name": "hits", "delta": 1 } + ] + } + } + ] +} +--- backend +server_name test_backend.lvh.me; + location /transactions/authrep.xml { + content_by_lua_block { + ngx.exit(ngx.OK) + } + } +--- upstream env +server_name test-upstream.lvh.me; +listen $TEST_NGINX_RANDOM_PORT ssl; +ssl_certificate $TEST_NGINX_SERVER_ROOT/html/server.crt; +ssl_certificate_key $TEST_NGINX_SERVER_ROOT/html/server.key; +location / { + content_by_lua_block { + ngx.exit(200); + } +} +--- request eval +["GET /?user_key=value", "GET /metrics/"] +--- more_headers eval +["Host: one", "Host: metrics"] +--- error_code eval +[ 200, 200 ] +--- expected_response_body_like_multiple eval +[ +"", +[ + qr/upstream_response_time_seconds(.|\n)/, + qr/upstream_response_time_seconds_bucket\{service_id="",service_system_name="",le=".*"\} 1/, + qr/upstream_status\{status="200",service_id="",service_system_name=""\} 1/ +]] +--- no_error_log +[error] +--- user_files fixture=tls.pl eval + + +=== TEST 10: Report upstream metrics when using http_proxy policy +--- env eval +('BACKEND_ENDPOINT_OVERRIDE' => "http://test_backend.lvh.me:$ENV{TEST_NGINX_SERVER_PORT}") +--- configuration random_port env +{ + "services": [ + { + "id": 42, + "backend_version": 1, + "backend_authentication_type": "service_token", + "backend_authentication_value": "token-value", + "proxy": { + "hosts": ["one"], + "api_backend": "https://test-upstream.lvh.me:$TEST_NGINX_RANDOM_PORT", + "proxy_rules": [ + { "pattern": "/", "http_method": "GET", "metric_system_name": "hits", "delta": 1 } + ], + "policy_chain": [ + { + "name": "apicast.policy.apicast" + }, + { + "name": "apicast.policy.http_proxy", + "configuration": { + "https_proxy": "$TEST_NGINX_HTTPS_PROXY" + } + } + ] + } + } + ] +} +--- backend +server_name test_backend.lvh.me; + location /transactions/authrep.xml { + content_by_lua_block { + ngx.exit(ngx.OK) + } + } +--- upstream env +server_name test-upstream.lvh.me; +listen $TEST_NGINX_RANDOM_PORT ssl; +ssl_certificate $TEST_NGINX_SERVER_ROOT/html/server.crt; +ssl_certificate_key $TEST_NGINX_SERVER_ROOT/html/server.key; +location / { + content_by_lua_block { + ngx.exit(200); + } +} +--- request eval +["GET /?user_key=value", "GET /metrics/"] +--- more_headers eval +["Host: one", "Host: metrics"] +--- error_code eval +[ 200, 200 ] +--- expected_response_body_like_multiple eval +[ +"", +[ + qr/upstream_response_time_seconds(.|\n)/, + qr/upstream_response_time_seconds_bucket\{service_id="",service_system_name="",le=".*"\} 1/, + qr/upstream_status\{status="200",service_id="",service_system_name=""\} 1/ +]] +--- no_error_log +[error] +--- user_files fixture=tls.pl eval + + +=== TEST 11: Report upstream metrics when using camel policy +--- init eval +$Test::Nginx::Util::PROXY_SSL_PORT = Test::APIcast::get_random_port(); +$Test::Nginx::Util::ENDPOINT_SSL_PORT = Test::APIcast::get_random_port(); +--- configuration random_port env eval +<