THREESCALE-10571 fix(proxy*): set upstream metrics when sending request via proxy

CHANGELOG.md

@@ -17,6 +17,7 @@ and this project adheres to [Semantic Versioning](http://semver.org/).
 - Only validate oidc setting if authentication method is set to oidc [PR #1568](https://github.com/3scale/APIcast/pull/1568) [THREESCALE-11441](https://issues.redhat.com/browse/THREESCALE-11441)
 - Reduce memory consumption when returning large response that has been routed through a proxy server. [PR #1572](https://github.com/3scale/APIcast/pull/1572) [THREESCALE-12258](https://issues.redhat.com/browse/THREESCALE-12258)
 - Fix proxy policy doesn't send headers set by APIcast to the API Backend. [PR #1588](https://github.com/3scale/APIcast/pull/1588) [THREESCALE-10151](https://redhat.atlassian.net/browse/THREESCALE-10151)
+- 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)

gateway/src/apicast/http_proxy.lua

@@ -56,6 +56,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

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

spec/http_proxy_spec.lua

@@ -9,11 +9,11 @@ describe('http_proxy', function()
       stub(ngx.req, 'get_method', function() return 'GET' end)
     end
 
-    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')
@@ -24,11 +24,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 = {
@@ -41,14 +36,25 @@ 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)
       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)

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
+<<EOF
+{
+  "services": [
+    {
+      "id": 42,
+      "backend_version":  1,
+      "backend_authentication_type": "service_token",
+      "backend_authentication_value": "token-value",
+      "proxy": {
+        "hosts": ["one"],
+        "secret_token": "token",
+        "api_backend": "https://localhost:$Test::Nginx::Util::ENDPOINT_SSL_PORT",
+        "proxy_rules": [
+          { "pattern": "/", "http_method": "GET", "metric_system_name": "hits", "delta": 1 }
+        ],
+        "policy_chain": [
+          {
+            "name": "apicast.policy.apicast"
+          },
+          {
+            "name": "apicast.policy.camel",
+            "configuration": {
+                "https_proxy": "http://127.0.0.1:$Test::Nginx::Util::PROXY_SSL_PORT"
+            }
+          }
+        ]
+      }
+    }
+  ]
+}
+EOF
+--- backend
+  location /transactions/authrep.xml {
+    content_by_lua_block {
+      ngx.exit(ngx.OK)
+    }
+  }
+--- upstream eval
+<<EOF
+  # Endpoint config
+  listen $Test::Nginx::Util::ENDPOINT_SSL_PORT ssl;
+
+  ssl_certificate $Test::Nginx::Util::ServRoot/html/server.crt;
+  ssl_certificate_key $Test::Nginx::Util::ServRoot/html/server.key;
+
+  server_name _ default_server;
+
+  location / {
+    content_by_lua_block {
+      ngx.exit(200)
+    }
+  }
+}
+server {
+  # Proxy config
+  listen $Test::Nginx::Util::PROXY_SSL_PORT ssl;
+
+  ssl_certificate $Test::Nginx::Util::ServRoot/html/server.crt;
+  ssl_certificate_key $Test::Nginx::Util::ServRoot/html/server.key;
+
+  server_name _ default_server;
+
+  location ~ /.* {
+    proxy_http_version 1.1;
+    proxy_pass https://\$http_host;
+  }
+EOF
+--- 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