bug: Two requests returned differently

[mushenglon-sudo]

Current Behavior

-- Licensed to the Apache Software Foundation (ASF) under one or more
-- contributor license agreements.  See the NOTICE file distributed with
-- this work for additional information regarding copyright ownership.
-- The ASF licenses this file to You under the Apache License, Version 2.0
-- (the "License"); you may not use this file except in compliance with
-- the License.  You may obtain a copy of the License at
--
--     http://www.apache.org/licenses/LICENSE-2.0
--
-- Unless required by applicable law or agreed to in writing, software
-- distributed under the License is distributed on an "AS IS" BASIS,
-- WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-- See the License for the specific language governing permissions and
-- limitations under the License.
--
local core = require("apisix.core")
local helper = require("apisix.plugins.ext-plugin.helper")
local constants = require("apisix.constants")
local http = require("resty.http")
local cjson    = require("cjson.safe") 

local ngx       = ngx
local ngx_print = ngx.print
local ngx_flush = ngx.flush
local string    = string
local str_sub   = string.sub


local schema = {
    type = "object",
    properties = {
        xCeaiServiceId = {type = "string"},
        allow_degradation = {type = "boolean", default = false},
        status_on_error = {type = "integer", minimum = 200, maximum = 599, default = 403},
        ssl_verify = {
            type = "boolean",
            default = true,
        },
        request_method = {
            type = "string",
            default = "POST",
            enum = {"GET", "POST"},
            description = "the method for client to request the authorization service"
        },
        request_headers = {
            type = "array",
            default = {},
            items = {type = "string"},
            description = "client request header that will be sent to the authorization service"
        },
        extra_headers = {
            type = "object",
            minProperties = 1,
            patternProperties = {
                ["^[^:]+$"] = {
                    type = "string",
                    description = "header value as a string; may contain variables"
                                  .. "like $remote_addr, $request_uri"
                }
            },
            description = "extra headers sent to the authorization service; "
                        .. "values must be strings and can include variables"
                        .. "like $remote_addr, $request_uri."
        },
        upstream_headers = {
            type = "array",
            default = {},
            items = {type = "string"},
            description = "authorization response header that will be sent to the upstream"
        },
        client_headers = {
            type = "array",
            default = {},
            items = {type = "string"},
            description = "authorization response header that will be sent to"
                           .. "the client when authorizing failed"
        },
        timeout = {
            type = "integer",
            minimum = 1,
            maximum = 60000,
            default = 3000,
            description = "timeout in milliseconds",
        },
        keepalive = {type = "boolean", default = true},
        keepalive_timeout = {type = "integer", minimum = 1000, default = 60000},
        keepalive_pool = {type = "integer", minimum = 1, default = 5},
    },
    required = {"xCeaiServiceId"}
}
local name = "custom-output-check"
local _M = {
    version = 0.1,
    priority = 2006,
    name = name,
    schema = schema,
}

function _M.check_schema(conf)
    core.utils.check_tls_bool({"ssl_verify"}, conf, _M.name)
    return core.schema.check(_M.schema, conf)
end


local function include_req_headers(ctx)
    return core.request.headers(ctx)
end


local function close(http_obj)
    local ok, err = http_obj:close()
    if not ok and err ~= "closed" then
        core.log.error("close http object failed: ", err)
    end
end


local function get_response(ctx,conf)
    local http_obj = http.new()
    local ok, err = http_obj:connect({
        scheme = ctx.upstream_scheme,
        host = ctx.picked_server.host,
        port = ctx.picked_server.port,
    })
    if not ok then
        return nil, err
    end
    http_obj:set_timeout(conf.timeout)
    
    local uri = ctx.var.uri
    local args = ctx.var.args or ""
    
    -- 生成唯一请求标识
    local request_id = ngx.md5(ngx.now() .. math.random(10000, 99999))
    
    -- 构建防缓存参数
    local cache_buster = "&_nc=" .. request_id
    local new_args = args .. cache_buster
    
    local params = {
        path = uri,
        query = new_args,
        headers = include_req_headers(ctx),
        method = core.request.get_method(),
    }
    
    -- 强制设置防缓存头
    local headers = params.headers
    headers["X-Request-ID"] = request_id
    headers["Cache-Control"] = "no-cache, no-store, must-revalidate"
    headers["Pragma"] = "no-cache"
    headers["Expires"] = "0"
    headers["X-No-Cache"] = "1"
    
    -- 如果是POST请求，添加时间戳到body（如果body是JSON）
    local body, err = core.request.get_body()
    local modified_body = body
    
    if body and not err then
        local content_type = headers["Content-Type"] or headers["content-type"] or ""
        if content_type:find("application/json") then
            local ok, json_data = pcall(cjson.decode, body)
            if ok and type(json_data) == "table" then
                json_data._request_id = request_id
                json_data._timestamp = math.floor(ngx.now() * 1000)
                modified_body = cjson.encode(json_data)
                headers["Content-Length"] = tostring(#modified_body)
            end
        end
    end

    if modified_body then
        params["body"] = modified_body
    end
    
    core.log.error("=====================防缓存请求=====================")
    core.log.error("Request ID: ", request_id)
    core.log.error("URL: ", uri .. "?" .. new_args)
    
    local res, err = http_obj:request(params)
    local body_content = ""
    
    if res and res.body_reader then
        local chunk, err
        while true do
            chunk, err = res.body_reader()
            if err then
                core.log.error("read response body error: ", err)
                break
            end
            if not chunk then
                break
            end
            body_content = body_content .. chunk
        end
    end
    
    core.log.error("=====================响应信息=====================")
    core.log.error("Status: ", res and res.status or "no response")
    core.log.error("Request ID: ", request_id)
    core.log.error("=====================认证服务响应=====================")
    core.log.error("认证服务状态码: ", res.status)
    core.log.error("认证服务响应体: ", body_content)
    
    if not res then
        close(http_obj)
        return nil, err
    end
    
    close(http_obj)
    return res, body_content, nil
end

local function send_chunk(body_content)
    local ok, print_err = ngx_print(body_content)
    if not ok then
        return "output response failed: ".. (print_err or "")
    end
    local ok, flush_err = ngx_flush(true)
    if not ok then
        core.log.warn("flush response failed: ", flush_err)
    end
    return nil
end


local function send_response(ctx, code, body_content)
    ngx.status = code or 500
    -- 发送响应体
    local err = send_chunk(body_content)
    if err then
        return err
    end
    return nil
end

function _M.before_proxy(conf, ctx)
    local res, body_content, err = get_response(ctx,conf)
    if not res or err then
        return 502
    end
    local code = (res and res.status) or 500
    if res and res.status == 200 then
        -- 业务逻辑
        local auth_headers = {
            ["X-Forwarded-Proto"] = core.request.get_scheme(ctx),
            ["X-Forwarded-Method"] = core.request.get_method(),
            ["X-Forwarded-Host"] = core.request.get_host(ctx),
            ["X-Ceai-Service-Id"] = conf.xCeaiServiceId,  -- 添加模型ID到请求头
            ["X-Forwarded-Uri"] = ctx.var.request_uri,
            ["X-Forwarded-For"] = core.request.get_remote_client_ip(ctx),
        }
        if conf.request_method == "POST" then
            auth_headers["Content-Length"] = core.request.header(ctx, "content-length")
            auth_headers["Expect"] = core.request.header(ctx, "expect")
            auth_headers["Transfer-Encoding"] = core.request.header(ctx, "transfer-encoding")
            auth_headers["Content-Encoding"] = core.request.header(ctx, "content-encoding")
        end
        if conf.extra_headers then
            for header, value in pairs(conf.extra_headers) do
                if type(value) == "number" then
                    value = tostring(value)
                end
                local resolve_value, err = core.utils.resolve_var(value, ctx.var)
                if not err then
                    auth_headers[header] = resolve_value
                end
                if err then
                    core.log.error("failed to resolve variable in extra header '",
                                    header, "': ",value,": ",err)
                end
            end
        end

        -- append headers that need to be get from the client request header
        if #conf.request_headers > 0 then
            for _, header in ipairs(conf.request_headers) do
                if not auth_headers[header] then
                    auth_headers[header] = core.request.header(ctx, header)
                end
            end
        end

        local params = {
            headers = auth_headers,
            keepalive = conf.keepalive,
            ssl_verify = conf.ssl_verify,
            method = "POST",  -- 固定使用POST方法
            body = body_content,
        }
        if conf.keepalive then
            params.keepalive_timeout = conf.keepalive_timeout
            params.keepalive_pool = conf.keepalive_pool
        end

        local httpc = http.new()
        httpc:set_timeout(conf.timeout)
        local res, err = httpc:request_uri(conf.uri, params)
        close(httpc)
        if not res and conf.allow_degradation then
            return
        elseif not res then
            core.log.warn("failed to process forward auth, err: ", err)
            err = send_response(ctx,conf.status_on_error,"")
            return 
        end
        -- 修改：处理鉴权响应的逻辑
        if res.status >= 300 then
            local client_headers = {}
            if #conf.client_headers > 0 then
                for _, header in ipairs(conf.client_headers) do
                    client_headers[header] = res.headers[header]
                end
            end
            core.response.set_header(client_headers)
            err = send_response(ctx,  res.status, res.body)
            return 
        end
        -- 2. 解析响应体判断鉴权结果
        local auth_body, parse_err = cjson.decode(res.body)
        if not auth_body then
            -- 记录详细错误：原始响应体+解析错误
            core.log.error("failed to parse authorization response: ", 
                            "body=", res.body, ", error=", parse_err)

            err = send_response(ctx,  500, parse_err)
        return 
        end
        
        if not auth_body.statusCode then
            core.log.error("statusCode is nil auth_body=", auth_body)
            err = send_response(ctx,  500, "statusCode is nil")
            return 
        end
        -- 3. 检查statusCode字段，statusCode不等于0表示鉴权失败
        if auth_body.statusCode and auth_body.statusCode ~= 0 then
            local client_headers = {}
            if #conf.client_headers > 0 then
                for _, header in ipairs(conf.client_headers) do
                    client_headers[header] = res.headers[header]
                end
            end
            core.response.set_header(client_headers)
            err = send_response(ctx, res.status, res.body)
            return 
        end
        -- 4. 鉴权成功，传递指定的响应头给上游服务
        for _, header in ipairs(conf.upstream_headers) do
            local header_value = res.headers[header]
            if header_value then
                core.request.set_header(ctx, header, header_value)
            end
        end
    end
    -- send origin response, status maybe changed.
    err = send_response(ctx, code, body_content)
    if err then
        core.log.error("send response error: ", tostring(err))
        return not ngx.headers_sent and 502 or nil
    end
    return 
end
return _M

[{"finish_reason":"length","index":0,"logprobs":null,"prompt_logprobs":null,"prompt_token_ids":null,"stop_reason":null,"text":"M78星云与成都有什么关联吗？M78星云与成都有什么关联吗？M78星云与成都有什么关联吗？M78星云与成都有什么关联吗？M78星云与成都有什么关联吗？M78星云与成都有什么关联吗？M78星","token_ids":null}],"created":1763014030,"id":"cmpl-ad0ecc9b60954d059f77aef4c5f62c3a","kv_transfer_params":null,"model":"model","object":"text_completion","service_tier":null,"system_fingerprint":null,"usage":{"completion_tokens":70,"prompt_tokens":13,"prompt_tokens_details":null,"total_tokens":83}}}, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

192.168.65.1 - - [16/Nov/2025:15:22:26 +0000] 127.0.0.1:9080 "POST /protected-word-manager/api/v1/Content HTTP/1.1" 400 63 0.015 "-" "PostmanRuntime/7.50.0" - - - "http://127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:176: get_response(): =====================防缓存请求=====================, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:177: get_response(): Request ID: 081dfff041ec1be194c82307cd1f3014, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:178: get_response(): URL: /protected-word-manager/api/v1/Content?&_nc=081dfff041ec1be194c82307cd1f3014, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:198: get_response(): =====================响应信息=====================, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:199: get_response(): Status: 400, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:200: get_response(): Request ID: 081dfff041ec1be194c82307cd1f3014, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:201: get_response(): =====================认证服务响应=====================, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:202: get_response(): 认证服务状态码: 400, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

2025/11/16 15:22:29 [error] 49#49: *954 [lua] custom-output-check.lua:203: get_response(): 认证服务响应体: 400 Bad Request, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

192.168.65.1 - - [16/Nov/2025:15:22:29 +0000] 127.0.0.1:9080 "POST /protected-word-manager/api/v1/Content HTTP/1.1" 400 25 0.003 "-" "PostmanRuntime/7.50.0" - - - "http://127.0.0.1:9080"

Expected Behavior

No response

Error Logs

No response

Steps to Reproduce

Run APISIX via the Docker image

Environment

• APISIX version (run apisix version):
• Operating system (run uname -a):
• OpenResty / Nginx version (run openresty -V or nginx -V):
• etcd version, if relevant (run curl http://127.0.0.1:9090/v1/server_info):
• APISIX Dashboard version, if relevant:
• Plugin runner version, for issues related to plugin runners:
• LuaRocks version, for installation issues (run luarocks --version):

[shreemaan-abhishek]

please describe the actual issue you are facing in detail.

It is difficult for us to go through the code and all the logs and find out the issue ourselves. Thanks for your cooperation.

[Baoyuantop]

Hi @mushenglon-sudo, please describe your problem in detail, including how you sent the request, what the expected result was, and what the actual result was.

[mushenglon-sudo]

I used the address of upstream in the _M.before_proxy stage
local http_obj = http.new()
local ok, err = http_obj:connect({
scheme = ctx.upstream_scheme,
host = ctx.picked_server.host,
port = ctx.picked_server.port,
})
Then use it again
local httpc = http.new()
httpc:set_timeout(conf.timeout)
local res, err = httpc:request_uri(conf.uri, params)
httpc:close()
The same client requests twice
Two returns are different

The first time was right

The second time is
400 Bad Request, client: 192.168.65.1, server: _, request: "POST /protected-word-manager/api/v1/Content HTTP/1.1", host: "127.0.0.1:9080"

[mushenglon-sudo]

Wait a few minutes. Executing the second time is also right

[mushenglon-sudo]

I hope that the same client and curl will return the same result no matter how many requests are made

[Baoyuantop]

Hi @mushenglon-sudo, what would happen if you made two direct requests to your upstream service?

[mushenglon-sudo]

Is it possible to access the upstream address directly without going through Apisix? The two requests are identical

[mushenglon-sudo]

I think using two http. new() in the same plugin for external communication. There will be bug，You can have a try @Baoyuantop

[Baoyuantop]

Hi @mushenglon-sudo, could you provide a minimal example of how to reproduce this? I will try to reproduce it.