feat: support apisix_request_id variable with request-id plugin (#12931)

Author: shreemaan-abhishek

apisix/cli/config.lua

@@ -110,7 +110,7 @@ local _M = {
       enable_access_log = false,
       access_log = "logs/access_stream.log",
       -- luacheck: push max code line length 300
-      access_log_format = "$remote_addr [$time_local] $protocol $status $bytes_sent $bytes_received $session_time",
+      access_log_format = "$remote_addr [$time_local] $protocol $status $bytes_sent $bytes_received $session_time $apisix_request_id",
       -- luacheck: pop
       access_log_format_escape = "default",
       lua_shared_dict = {

apisix/cli/ngx_tpl.lua

@@ -640,6 +640,10 @@ http {
         allow all;
         {%end%}
 
+        {% if use_apisix_base then %}
+        set $apisix_request_id $request_id;
+        lua_error_log_request_id $apisix_request_id;
+        {% end %}
         location /apisix/admin {
             content_by_lua_block {
                 apisix.http_admin()
@@ -819,6 +823,11 @@ http {
             set $llm_completion_tokens          '0';
 
 
+            {% if use_apisix_base then %}
+            set $apisix_request_id $request_id;
+            lua_error_log_request_id $apisix_request_id;
+            {% end %}
+
             access_by_lua_block {
                 apisix.http_access_phase()
             }

apisix/core/ctx.lua

@@ -234,6 +234,7 @@ do
         upstream_connection        = true,
         upstream_uri               = true,
         llm_content_risk_level     = true,
+        apisix_request_id          = true,
 
         request_type               = true,
         apisix_upstream_response_time = true,

apisix/plugins/request-id.lua

@@ -112,6 +112,9 @@ function _M.rewrite(conf, ctx)
     if conf.include_in_response then
         ctx["request-id-" .. conf.header_name] = uuid_val
     end
+    if ctx.var.apisix_request_id then
+        ctx.var.apisix_request_id = uuid_val
+    end
 end
 
 function _M.header_filter(conf, ctx)

t/APISIX.pm

@@ -870,6 +870,9 @@ _EOC_
             set \$apisix_upstream_response_time  \$upstream_response_time;
             access_log $apisix_home/t/servroot/logs/access.log main;
 
+            set \$apisix_request_id \$request_id;
+            lua_error_log_request_id \$apisix_request_id;
+
             access_by_lua_block {
                 -- wait for etcd sync
                 ngx.sleep($wait_etcd_sync)

t/cli/test_access_log.sh

@@ -129,6 +129,11 @@ if [ `grep -c '"client_ip": "127.0.0.1"' output.log` -eq '0' ]; then
     exit 1
 fi
 
+if [ `grep -E "^{[^}]+}$" output.log` -eq '0' ]; then
+    echo "failed: invalid JSON log in access log"
+    exit 1
+fi
+
 if [ `grep -c 'main escape=json' conf/nginx.conf` -eq '0' ]; then
     echo "failed: not found \"escape=json\" in conf/nginx.conf"
     exit 1
@@ -138,6 +143,30 @@ make stop
 
 echo "passed: access log with JSON format"
 
+
+# access log with default log format
+echo '
+nginx_config:
+  http:
+    enable_access_log: true
+' > conf/config.yaml
+
+make init
+make run
+sleep 0.1
+curl http://127.0.0.1:9080/hello2
+sleep 4
+tail -n 1 logs/access.log > output.log
+
+if [ `grep -E '[0-9|.]+ - - \[[^]]+\] [0-9|.:]+ "[^"]+" [0-9]+ [0-9]+ [0|.]+ "-" "[^"]+" - - - "[^"]+" ".{36}"' output.log` -eq '0' ]; then
+    echo "failed: access log don't match default log format"
+    exit 1
+fi
+
+make stop
+
+echo "passed: access log with default format"
+
 # access log with unset llm_token JSON format
 
 echo '

t/node/upstream-discovery-dynamic.t

@@ -121,13 +121,13 @@ GET /t
 --- grep_error_log eval
 qr/upstream: \S+, host: \S+/
 --- grep_error_log_out
-upstream: "http://127.0.0.1:1111/", host: "a.myhost.com"
-upstream: "http://127.0.0.1:1111/", host: "a.myhost.com"
-upstream: "http://127.0.0.1:2222/", host: "b.myhost.com"
-upstream: "http://127.0.0.1:2222/", host: "b.myhost.com"
-upstream: "http://127.0.0.1:1111/", host: "a.myhost.com"
-upstream: "http://127.0.0.1:2222/", host: "b.myhost.com"
-upstream: "http://127.0.0.1:2222/", host: "b.myhost.com"
-upstream: "http://127.0.0.1:1111/", host: "a.myhost.com"
-upstream: "http://127.0.0.1:2222/", host: "b.myhost.com"
-upstream: "http://127.0.0.1:1111/", host: "a.myhost.com"
+upstream: "http://127.0.0.1:1111/", host: "a.myhost.com",
+upstream: "http://127.0.0.1:1111/", host: "a.myhost.com",
+upstream: "http://127.0.0.1:2222/", host: "b.myhost.com",
+upstream: "http://127.0.0.1:2222/", host: "b.myhost.com",
+upstream: "http://127.0.0.1:1111/", host: "a.myhost.com",
+upstream: "http://127.0.0.1:2222/", host: "b.myhost.com",
+upstream: "http://127.0.0.1:2222/", host: "b.myhost.com",
+upstream: "http://127.0.0.1:1111/", host: "a.myhost.com",
+upstream: "http://127.0.0.1:2222/", host: "b.myhost.com",
+upstream: "http://127.0.0.1:1111/", host: "a.myhost.com",

t/plugin/request-id3.t

@@ -152,3 +152,52 @@ X-Request-Id
 --- wait: 5
 --- response_body
 true
+
+
+
+=== TEST 4: enable request-id plugin
+--- yaml_config
+--- config
+    location /t {
+        content_by_lua_block {
+            local t = require("lib.test_admin").test
+            local code, body = t('/apisix/admin/routes/1',
+                 ngx.HTTP_PUT,
+                 [[{
+                        "plugins": {
+                            "request-id": {
+                                "header_name": "X-Request-Id"
+                            }
+                        },
+                        "upstream": {
+                            "nodes": {
+                                "127.0.0.1:1999": 1
+                            },
+                            "type": "roundrobin"
+                        },
+                        "uri": "/opentracing"
+                }]]
+                )
+            if code >= 300 then
+                ngx.status = code
+            end
+            ngx.say(body)
+        }
+    }
+--- response_body
+passed
+
+
+
+=== TEST 5: check request-id
+--- request
+GET /opentracing
+--- more_headers
+X-Request-Id: abctesting
+--- grep_error_log eval
+qr/request_id: "abctesting"/
+--- grep_error_log_out
+request_id: "abctesting"
+request_id: "abctesting"
+request_id: "abctesting"
+--- error_code: 502