8000 使用 Lua 模块的 ngx.location.capture 时 504 · Issue #1991 · alibaba/tengine · GitHub
[go: up one dir, main page]
More Web Proxy on the site http://driver.im/
Skip to content

8000 使用 Lua 模块的 ngx.location.capture 时 504 #1991

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Open
yelili422 opened this issue Apr 9, 2025 · 2 comments
Open

使用 Lua 模块的 ngx.location.capture 时 504 #1991

yelili422 opened this issue Apr 9, 2025 · 2 comments

Comments

@yelili422
Copy link

Ⅰ. Issue Description

使用 Lua 模块的 ngx.location.capture api 时报错 504

Ⅱ. Describe what happened

Ⅲ. Describe what you expected to happen

Ⅳ. How to reproduce it (as minimally and precisely as possible)

  1. 编译条件
./configure --prefix=/etc/nginx \
  --sbin-path=/usr/sbin/nginx \
  --modules-path=/usr/lib/nginx/modules \
  --conf-path=/etc/nginx/nginx.conf \
  --with-ld-opt='-Wl,-rpath,/usr/local/luajit/lib,--as-needed -pie' \
  --add-module=modules/ngx_http_lua_module \
            --with-debug --with-cc-opt='-g -O0'
  1. nginx 配置
location /test {
           content_by_lua_block {
                local res = ngx.location.capture("/backend", { method = ngx.HTTP_GET, body = "" })
                if res.status == 200 then
                    ngx.say("Backend response: ", res.body)
                else
                    ngx.status = res.status
                    ngx.say("Error: ", res.status)
                end
            }
}

location /backend {
    proxy_pass http://127.0.0.1:8080;
}
  1. curl 测试
curl http://localhost/test
Error: 504

Ⅴ. Anything else we need to know?

Ⅵ. Environment:

  • Tengine version (use sbin/nginx -V):
    Tengine version: Tengine/3.1.0
    nginx version: nginx/1.24.0
    built by gcc 12.2.0 (Debian 12.2.0-14)
    built with OpenSSL 3.0.15 3 Sep 2024
    TLS SNI support enabled
    configure arguments: --prefix=/etc/nginx --sbin-path=/usr/sbin/nginx --modules-path=/usr/lib/nginx/modules --conf-path=/etc/nginx/nginx.conf --with-ld-opt='-Wl,-rpath,/usr/local/luajit/lib,--as-needed -pie' --add-module=modules/ngx_http_lua_module --with-debug --with-cc-opt='-g -O0'
  • OS (e.g. from /etc/os-release):
    PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
    NAME="Debian GNU/Linux"
    VERSION_ID="12"
    VERSION="12 (bookworm)"
    VERSION_CODENAME=bookworm
  • Kernel (e.g. uname -a):
  • Others:
@yelili422
Copy link
Author

日志

2025/04/08 18:30:41 [debug] 114252#0: accept on 0.0.0.0:80, ready: 0
2025/04/08 18:30:41 [debug] 114252#0: posix_memalign: 000055555588ED60:512 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 accept: 127.0.0.1:47722 fd:4
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer add: 4: 60000:88054790
2025/04/08 18:30:41 [debug] 114252#0: *1 reusable connection: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 epoll add event: fd:4 op:1 ev:80002001
2025/04/08 18:30:41 [debug] 114252#0: *1 http wait request handler
2025/04/08 18:30:41 [debug] 114252#0: *1 malloc: 000055555585A340:1024
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: eof:0, avail:-1
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: fd:4 77 of 1024
2025/04/08 18:30:41 [debug] 114252#0: *1 reusable connection: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 posix_memalign: 0000555555869150:4096 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 http process request line
2025/04/08 18:30:41 [debug] 114252#0: *1 http request line: "GET /test HTTP/1.1"
2025/04/08 18:30:41 [debug] 114252#0: *1 http uri: "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http args: ""
2025/04/08 18:30:41 [debug] 114252#0: *1 http exten: ""
2025/04/08 18:30:41 [debug] 114252#0: *1 posix_memalign: 000055555585F010:4096 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 http process request header line
2025/04/08 18:30:41 [debug] 114252#0: *1 http header: "Host: localhost"
2025/04/08 18:30:41 [debug] 114252#0: *1 http header: "User-Agent: curl/7.88.1"
2025/04/08 18:30:41 [debug] 114252#0: *1 http header: "Accept: */*"
2025/04/08 18:30:41 [debug] 114252#0: *1 http header done
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer del: 4: 88054790
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 test location: "/"
2025/04/08 18:30:41 [debug] 114252#0: *1 test location: "backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 test location: "test"
2025/04/08 18:30:41 [debug] 114252#0: *1 using configuration "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http cl:-1 max:1048576
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 3
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 4
2025/04/08 18:30:41 [debug] 114252#0: *1 post rewrite phase: 5
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 6
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 7
2025/04/08 18:30:41 [debug] 114252#0: *1 access phase: 8
2025/04/08 18:30:41 [debug] 114252#0: *1 access phase: 9
2025/04/08 18:30:41 [debug] 114252#0: *1 post access phase: 10
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 11
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 12
2025/04/08 18:30:41 [debug] 114252#0: *1 lua content handler, uri:"/test" c:1
2025/04/08 18:30:41 [debug] 114252#0: *1 code cache lookup (key='content_by_lua_nhli_3cecd8dfca5e6cd867504a981fa91a54', ref=-1)
2025/04/08 18:30:41 [debug] 114252#0: *1 code cache miss (key='content_by_lua_nhli_3cecd8dfca5e6cd867504a981fa91a54', ref=-1)
2025/04/08 18:30:41 [debug] 114252#0: *1 lua reset ctx
2025/04/08 18:30:41 [debug] 114252#0: *1 http lua finalize threads
2025/04/08 18:30:41 [debug] 114252#0: *1 lua creating new thread
2025/04/08 18:30:41 [debug] 114252#0: *1 add cleanup: 000055555586A080
2025/04/08 18:30:41 [debug] 114252#0: *1 lua run thread, top:8 c:1
2025/04/08 18:30:41 [debug] 114252#0: *1 lua location capture, uri:"/test" c:1
2025/04/08 18:30:41 [debug] 114252#0: *1 posix_memalign: 0000555555860020:4096 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 lua http subrequest "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua resume returned 1
2025/04/08 18:30:41 [debug] 114252#0: *1 lua thread yielded
2025/04/08 18:30:41 [debug] 114252#0: *1 http finalize request: -4, "/test?" a:1, c:3
2025/04/08 18:30:41 [debug] 114252#0: *1 http request count:3 blk:0
2025/04/08 18:30:41 [debug] 114252#0: *1 http posted request: "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 test location: "/"
2025/04/08 18:30:41 [debug] 114252#0: *1 test location: "backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 using configuration "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 http cl:-1 max:1048576
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 3
2025/04/08 18:30:41 [debug] 114252#0: *1 rewrite phase: 4
2025/04/08 18:30:41 [debug] 114252#0: *1 post rewrite phase: 5
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 6
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 7
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 11
2025/04/08 18:30:41 [debug] 114252#0: *1 generic phase: 12
2025/04/08 18:30:41 [debug] 114252#0: *1 http init upstream, client timer: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 epoll add event: fd:4 op:3 ev:80002005
2025/04/08 18:30:41 [debug] 114252#0: *1 http script copy: "Host"
2025/04/08 18:30:41 [debug] 114252#0: *1 http script var: "127.0.0.1:8080"
2025/04/08 18:30:41 [debug] 114252#0: *1 http script copy: "Connection"
2025/04/08 18:30:41 [debug] 114252#0: *1 http script copy: "close"
2025/04/08 18:30:41 [debug] 114252#0: *1 http script copy: ""
2025/04/08 18:30:41 [debug] 114252#0: *1 http script copy: ""
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header: "User-Agent: curl/7.88.1"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header: "Accept: */*"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header:
"GET /backend HTTP/1.0
Host: 127.0.0.1:8080
Connection: close
User-Agent: curl/7.88.1
Accept: */*

"
2025/04/08 18:30:41 [debug] 114252#0: *1 http cleanup add: 0000555555860DF8
2025/04/08 18:30:41 [debug] 114252#0: *1 get rr peer, try: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 stream socket 13
2025/04/08 18:30:41 [debug] 114252#0: *1 epoll add connection: fd:13 ev:80002005
2025/04/08 18:30:41 [debug] 114252#0: *1 connect to 127.0.0.1:8080, fd:13 #2
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream connect: -2
2025/04/08 18:30:41 [debug] 114252#0: *1 posix_memalign: 000055555586A160:128 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer add: 13: 60000:88054792
2025/04/08 18:30:41 [debug] 114252#0: *1 http finalize request: -4, "/backend?" a:0, c:3
2025/04/08 18:30:41 [debug] 114252#0: *1 http request count:3 blk:0
2025/04/08 18:30:41 [debug] 114252#0: *1 http run request: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http request empty handler
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream request: "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream send request handler
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream send request
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream send request body
2025/04/08 18:30:41 [debug] 114252#0: *1 chain writer buf fl:1 s:104
2025/04/08 18:30:41 [debug] 114252#0: *1 chain writer in: 0000555555860000
2025/04/08 18:30:41 [debug] 114252#0: *1 writev: 104 of 104
2025/04/08 18:30:41 [debug] 114252#0: *1 chain writer out: 0000000000000000
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer del: 13: 88054792
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer add: 13: 60000:88054799
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream request: "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream process header
2025/04/08 18:30:41 [debug] 114252#0: *1 malloc: 0000555555861030:4096
2025/04/08 18:30:41 [debug] 114252#0: *1 posix_memalign: 0000555555908DD0:4096 @16
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: eof:0, avail:-1
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: fd:13 156 of 4096
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy status 200 "200 OK"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header: "Date: Tue, 08 Apr 2025 10:30:41 GMT"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header: "Content-Length: 39"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header: "Content-Type: text/plain; charset=utf-8"
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy header done
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture header filter, uri "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capturing response body
2025/04/08 18:30:41 [debug] 114252#0: *1 http cacheable: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http proxy filter init s:200 h:0 c:0 l:39
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream process upstream
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe read upstream: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe preread: 39
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe buf free s:0 t:1 f:0 0000555555861030, pos 00005555558610A5, size: 39 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe length: 39
2025/04/08 18:30:41 [debug] 114252#0: *1 input buf #0
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe write downstream: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe write downstream flush in
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter capturing response body, uri "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua allocate new chainlink and new buf of size 39, cl:0000555555860000
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 pipe write downstream done
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer: 13, old: 88054799, new: 88054807
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream exit: 0000000000000000
2025/04/08 18:30:41 [debug] 114252#0: *1 finalize http upstream request: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 finalize http proxy request
2025/04/08 18:30:41 [debug] 114252#0: *1 free rr peer 1 0
2025/04/08 18:30:41 [debug] 114252#0: *1 close http upstream connection: 13
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 000055555586A160, unused: 48
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer del: 13: 88054799
2025/04/08 18:30:41 [debug] 114252#0: *1 reusable connection: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http upstream temp fd: -1
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter capturing response body, uri "/backend"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/backend?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http finalize request: 0, "/backend?" a:0, c:2
2025/04/08 18:30:41 [debug] 114252#0: *1 lua run post subrequest handler, rc:0 c:2
2025/04/08 18:30:41 [debug] 114252#0: *1 lua restoring write event handler
2025/04/08 18:30:41 [debug] 114252#0: *1 http wake parent request: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http posted request: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua run subrequests done, resuming lua thread
2025/04/08 18:30:41 [debug] 114252#0: *1 lua handle subrequest responses
2025/04/08 18:30:41 [debug] 114252#0: *1 lua run thread, top:8 c:1
2025/04/08 18:30:41 [error] 114252#0: *1 [lua] content_by_lua(nginx.conf:59):3: 200This is a fixed response from /backend
 while sending to client, client: 127.0.0.1, server: localhost, request: "GET /test HTTP/1.1", host: "localhost"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua reuse free buf memory 39 >= 20, cl:0000555555860000, p:00005555559090E0
2025/04/08 18:30:41 [debug] 114252#0: *1 lua say response
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture header filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 HTTP/1.1 200 OK
Server: openresty/1.27.1.2
Date: Tue, 08 Apr 2025 10:30:41 GMT
Content-Type: application/octet-stream
Transfer-Encoding: chunked
Connection: keep-alive

2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:0 f:0 s:176
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http postpone filter "/test?" 0000555555860000
2025/04/08 18:30:41 [debug] 114252#0: *1 http chunk: 12
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 0000555555909398, pos 0000555555909398, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 00005555559090E0, pos 00005555559090E0, size: 12 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:0 f:0 s:193
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua say response has busy bufs
2025/04/08 18:30:41 [debug] 114252#0: *1 lua allocate new chainlink and new buf of size 45, cl:0000555555909440
2025/04/08 18:30:41 [debug] 114252#0: *1 lua say response
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http postpone filter "/test?" 0000555555909440
2025/04/08 18:30:41 [debug] 114252#0: *1 http chunk: 45
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909398, pos 0000555555909398, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559090E0, pos 00005555559090E0, size: 12 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 0000555555909540, pos 0000555555909540, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 00005555559094A0, pos 00005555559094A0, size: 45 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:0 f:0 s:244
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua say response has busy bufs
2025/04/08 18:30:41 [debug] 114252#0: *1 lua allocate new chainlink and new buf of size 11, cl:00005555559095E8
2025/04/08 18:30:41 [debug] 114252#0: *1 lua print response
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http postpone filter "/test?" 00005555559095E8
2025/04/08 18:30:41 [debug] 114252#0: *1 http chunk: 3
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909398, pos 0000555555909398, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559090E0, pos 00005555559090E0, size: 12 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909540, pos 0000555555909540, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559094A0, pos 00005555559094A0, size: 45 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 00005555559096C8, pos 00005555559096C8, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 0000555555909648, pos 0000555555909648, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:0 f:0 s:252
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua print response has busy bufs
2025/04/08 18:30:41 [debug] 114252#0: *1 lua allocate new chainlink and new buf of size 39, cl:0000555555909770
2025/04/08 18:30:41 [debug] 114252#0: *1 lua print response
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http postpone filter "/test?" 0000555555909770
2025/04/08 18:30:41 [debug] 114252#0: *1 http chunk: 39
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909398, pos 0000555555909398, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559090E0, pos 00005555559090E0, size: 12 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909540, pos 0000555555909540, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0
8000
: *1 write old buf t:1 f:0 00005555559094A0, pos 00005555559094A0, size: 45 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559096C8, pos 00005555559096C8, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909648, pos 0000555555909648, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 0000555555909868, pos 0000555555909868, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:1 f:0 00005555559097D0, pos 00005555559097D0, size: 39 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:0 f:0 s:297
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua print response has busy bufs
2025/04/08 18:30:41 [debug] 114252#0: *1 lua resume returned 0
2025/04/08 18:30:41 [debug] 114252#0: *1 lua light thread ended normally
2025/04/08 18:30:41 [debug] 114252#0: *1 lua deleting light thread 00007FFFFF5FE990 (ref 1)
2025/04/08 18:30:41 [debug] 114252#0: *1 lua caching unused lua thread 00007FFFFF5FE990 (ref 1)
2025/04/08 18:30:41 [debug] 114252#0: *1 http set discard body
2025/04/08 18:30:41 [debug] 114252#0: *1 lua sending last buf of the response body
2025/04/08 18:30:41 [debug] 114252#0: *1 http output filter "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua capture body filter, uri "/test"
2025/04/08 18:30:41 [debug] 114252#0: *1 http postpone filter "/test?" 00005554FFFFEBC0
2025/04/08 18:30:41 [debug] 114252#0: *1 http chunk: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909200, pos 0000555555909200, size: 176 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909398, pos 0000555555909398, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559090E0, pos 00005555559090E0, size: 12 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909540, pos 0000555555909540, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559094A0, pos 00005555559094A0, size: 45 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559096C8, pos 00005555559096C8, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909648, pos 0000555555909648, size: 3 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 0000555555909868, pos 0000555555909868, size: 4 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:1 f:0 00005555559097D0, pos 00005555559097D0, size: 39 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write old buf t:0 f:0 0000000000000000, pos 00005555557969AE, size: 2 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 write new buf t:0 f:0 0000000000000000, pos 00005555557969B3, size: 5 file: 0, size: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter: l:1 f:0 s:302
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter limit 2097152
2025/04/08 18:30:41 [debug] 114252#0: *1 writev: 302 of 302
2025/04/08 18:30:41 [debug] 114252#0: *1 http write filter 0000000000000000
2025/04/08 18:30:41 [debug] 114252#0: *1 http copy filter: 0 "/test?"
2025/04/08 18:30:41 [debug] 114252#0: *1 lua run thread returned 0
2025/04/08 18:30:41 [debug] 114252#0: *1 http finalize request: 0, "/test?" a:1, c:1
2025/04/08 18:30:41 [debug] 114252#0: *1 set http keepalive handler
2025/04/08 18:30:41 [debug] 114252#0: *1 http close request
2025/04/08 18:30:41 [debug] 114252#0: *1 http log handler
2025/04/08 18:30:41 [debug] 114252#0: *1 run cleanup: 000055555586A080
2025/04/08 18:30:41 [debug] 114252#0: *1 lua request cleanup: forcible=0
2025/04/08 18:30:41 [debug] 114252#0: *1 http lua finalize threads
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 0000555555861030
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 0000555555869150, unused: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 000055555585F010, unused: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 0000555555860020, unused: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 0000555555908DD0, unused: 900
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 000055555585A340
2025/04/08 18:30:41 [debug] 114252#0: *1 hc free: 0000000000000000
2025/04/08 18:30:41 [debug] 114252#0: *1 hc busy: 0000000000000000 0
2025/04/08 18:30:41 [debug] 114252#0: *1 tcp_nodelay
2025/04/08 18:30:41 [debug] 114252#0: *1 reusable connection: 1
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer add: 4: 65000:88059807
2025/04/08 18:30:41 [debug] 114252#0: *1 http keepalive handler
2025/04/08 18:30:41 [debug] 114252#0: *1 malloc: 000055555585A340:1024
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: eof:1, avail:-1
2025/04/08 18:30:41 [debug] 114252#0: *1 recv: fd:4 0 of 1024
2025/04/08 18:30:41 [info] 114252#0: *1 client 127.0.0.1 closed keepalive connection
2025/04/08 18:30:41 [debug] 114252#0: *1 close http connection: 4
2025/04/08 18:30:41 [debug] 114252#0: *1 event timer del: 4: 88059807
2025/04/08 18:30:41 [debug] 114252#0: *1 reusable connection: 0
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 000055555585A340
2025/04/08 18:30:41 [debug] 114252#0: *1 free: 000055555588ED60, unused: 136

@yelili422
Copy link
Author

由于初始化 lua subreqeust 时没有对 connect_time 进行初始化

// tengine/src/http/ngx_http_upstream.c:1795
#if (T_HTTP_UPSTREAM_TIMEOUT_VAR)
        ngx_add_timer(c->write, (r->connect_time == NGX_CONF_UNSET_MSEC)
                      ? u->conf->connect_timeout : r->connect_time);
#else
        ngx_add_timer(c->write, u->conf->connect_timeout);
#endif

导致添加了 timeout 为 0 的定时器

修复建议：
在 ngx_http_lua_subrequest 中添加初始化代码

@yelili422 yelili422 mentioned this issue Apr 9, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@yelili422
0