Skip to content
This repository has been archived by the owner on Mar 17, 2024. It is now read-only.

[Bug] gRPC回落到nginx无法正确处理POST请求 #251

Open
HeXis-YS opened this issue Mar 1, 2023 · 1 comment
Open

[Bug] gRPC回落到nginx无法正确处理POST请求 #251

HeXis-YS opened this issue Mar 1, 2023 · 1 comment
Labels
bug Something isn't working

Comments

@HeXis-YS
Copy link

HeXis-YS commented Mar 1, 2023

Describe the bug【描述 bug】
在verysimple中配置通过gRPC回落到nginx (h2c)时,无法正确处理POST请求。看nginx日志似乎是verysimple没有正确处理参数,把参数省略掉了。

To Reproduce【如何复现该bug】
按所给出的配置文件运行verysimple,nginx和webd。
打开浏览器登录webd。

Expected behavior【预期的行为】
verysimple正确处理回落的POST请求,登录成功。

Envs (please complete the following information):【系统环境】
Clear Linux 38630, Kernel 6.2.1
verysimple 1088b27
nginx 1.20.2

Config file 【配置文件,客户端服务端配置都提供】

verysimple服务端
[app]
loglevel = 0
logfile = "/root/tmp/vs_log"

[[listen]]
tag = "vless-grpc-tls-in"
protocol = "vlesss"
uuid = "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"
ip = "0.0.0.0"
port = 9443
version = 0
advancedLayer = "grpc"
path = "grpc_path"
fallback = "/dev/shm/h2c.sock"
sniffing.enabled = false
cert = "/usr/local/etc/xray/cert.pem"
key = "/usr/local/etc/xray/cert.key"
extra.tls_minVersion = "1.3"
alpn = ["h2"]

[[listen]]
tag = "vless-tcp-in"
protocol = "vlesss"
uuid = "aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa"
ip = "0.0.0.0"
port = 8443
version = 0
fallback = "/dev/shm/h2c.sock"
sniffing.enabled = false
cert = "/usr/local/etc/xray/cert.pem"
key = "/usr/local/etc/xray/cert.key"
extra.tls_minVersion = "1.3"
alpn = ["h2"]
nginx.conf
worker_processes auto;
pid /run/nginx.pid;
include /etc/nginx/modules-enabled/*.conf;

events {
        worker_connections 2048;
        multi_accept on;
        use epoll;
}

http {
        sendfile on;
        tcp_nopush on;
        tcp_nodelay on;
        keepalive_timeout 15;
        types_hash_max_size 2048;

        include /etc/nginx/mime.types;
        default_type application/octet-stream;

        ssl_prefer_server_ciphers on;

        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log;

        gzip off;

        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
}

server {
        listen unix:/dev/shm/h2c.sock http2;

        client_header_timeout 52w;
        keepalive_timeout 52w;

        location / {
                proxy_pass http://127.0.0.1:80/;
                proxy_http_version 1.1;
        }
}

Debug Log 【Debug日志, 客户端 和 服务端 的 日志 都提供】

正常回落verysimple日志
{"L":"INFO ","T":"230301 023936.128","M":"Program started","loglvl":0}
{"L":"INFO ","T":"230301 023936.131","M":"zap log init complete.","logfile":"/root/tmp/vs_log"}
{"L":"INFO ","T":"230301 023936.134","M":"verysimple v1.2.5-1088b279ef77e4c34405ead8913588aaa83f425e, go1.20.1 linux amd64, with advLayer packages: [grpcSimple ws] \n"}
{"L":"INFO ","T":"230301 023936.134","M":"Working at","dir":"/root/tmp"}
{"L":"DEBUG","T":"230301 023936.135","M":"All Given Flags","flags":{"c":"my string representation"}}
{"L":"INFO ","T":"230301 023936.135","M":"Options","Log Level":"debug","UseReadv":true}
{"L":"INFO ","T":"230301 023936.137","M":"Starting..."}
{"L":"INFO ","T":"230301 023936.140","M":"Listening","tag":"vless-grpc-tls-in","protocol":"tls+grpc+vless","listen_addr":"0.0.0.0:9443","defaultClient":"dual+direct","dial_addr":""}
{"L":"INFO ","T":"230301 023936.143","M":"Listening","tag":"vless-tcp-in","protocol":"tls+vless","listen_addr":"0.0.0.0:8443","defaultClient":"dual+direct","dial_addr":""}
{"L":"INFO ","T":"230301 023947.603","M":"New Accepted Conn","connid":114949,"from":"1.2.3.4:60860","handler":"tls+vless://0.0.0.0:8443#vless-tcp-in"}
{"L":"WARN ","T":"230301 023947.911","M":"Failed handshakeInserver","connid":114949,"handler":"0.0.0.0:8443","client RemoteAddr":"1.2.3.4:60860","error":" [ Vless Invalid version  , Detail: invalid data, Data: 80 ] , with Buffer,len 148"}
{"L":"DEBUG","T":"230301 023947.912","M":"Fallback to default setting","addr":"/dev/shm/h2c.sock"}
{"L":"DEBUG","T":"230301 023947.912","M":"Default Route","connid":114949,"source":"/dev/shm/h2c.sock","client":"dual+direct","addr":""}
{"L":"INFO ","T":"230301 023947.912","M":"Request","connid":114949,"Fallback from":"1.2.3.4:60860","Target":"unix://%2Fdev%2Fshm%2Fh2c.sock","through":"dual+direct://"}
{"L":"DEBUG","T":"230301 023947.912","M":"handshake client with first payload","connid":114949,"len":148}
{"L":"DEBUG","T":"230301 023947.913","M":"TryCopy","id":114949,"from":"*net.UnixConn","->":"*tlsLayer.conn"}
{"L":"DEBUG","T":"230301 023947.913","M":"copying with readv","id":114949}
{"L":"DEBUG","T":"230301 023947.913","M":"TryCopy","id":114949,"from":"*tlsLayer.conn","->":"*net.UnixConn"}
{"L":"DEBUG","T":"230301 023947.913","M":"copying with classic method","id":114949}
{"L":"INFO ","T":"230301 024018.729","M":"Program got close signal."}
{"L":"INFO ","T":"230301 024018.730","M":"Stopping..."}
{"L":"DEBUG","T":"230301 024018.730","M":"netLayer.loopAccept, listener got closed","error":"accept tcp [::]:9443: use of closed network connection"}
{"L":"DEBUG","T":"230301 024018.730","M":"netLayer.loopAccept, listener got closed","error":"accept tcp [::]:8443: use of closed network connection"}
异常回落verysimple日志
{"L":"INFO ","T":"230301 024115.849","M":"Program started","loglvl":0}
{"L":"INFO ","T":"230301 024115.853","M":"zap log init complete.","logfile":"/root/tmp/vs_log"}
{"L":"INFO ","T":"230301 024115.854","M":"verysimple v1.2.5-1088b279ef77e4c34405ead8913588aaa83f425e, go1.20.1 linux amd64, with advLayer packages: [grpcSimple ws] \n"}
{"L":"INFO ","T":"230301 024115.855","M":"Working at","dir":"/root/tmp"}
{"L":"DEBUG","T":"230301 024115.855","M":"All Given Flags","flags":{"c":"my string representation"}}
{"L":"INFO ","T":"230301 024115.855","M":"Options","Log Level":"debug","UseReadv":true}
{"L":"INFO ","T":"230301 024115.857","M":"Starting..."}
{"L":"INFO ","T":"230301 024115.860","M":"Listening","tag":"vless-grpc-tls-in","protocol":"tls+grpc+vless","listen_addr":"0.0.0.0:9443","defaultClient":"dual+direct","dial_addr":""}
{"L":"INFO ","T":"230301 024115.862","M":"Listening","tag":"vless-tcp-in","protocol":"tls+vless","listen_addr":"0.0.0.0:8443","defaultClient":"dual+direct","dial_addr":""}
{"L":"INFO ","T":"230301 024124.310","M":"New Accepted Conn","connid":998747,"from":"1.2.3.4:33558","handler":"tls+grpc+vless://0.0.0.0:9443/grpc_path#vless-grpc-tls-in"}
{"L":"WARN ","T":"230301 024124.576","M":"grpc Server got wrong path","path":"/.auth"}
{"L":"INFO ","T":"230301 024124.578","M":"GrpcSimple will fallback","path":"/.auth","method":"POST","raddr":"1.2.3.4:33558"}
{"L":"DEBUG","T":"230301 024124.578","M":"Fallback to default setting","addr":"/dev/shm/h2c.sock"}
{"L":"DEBUG","T":"230301 024124.584","M":"TryCopy","id":998747,"from":"http2.noBodyReader","->":"*netLayer.IOWrapper"}
{"L":"DEBUG","T":"230301 024124.584","M":"copying with classic method","id":998747}
{"L":"INFO ","T":"230301 024130.567","M":"Program got close signal."}
{"L":"INFO ","T":"230301 024130.567","M":"Stopping..."}
{"L":"DEBUG","T":"230301 024130.568","M":"netLayer.loopAccept, listener got closed","error":"accept tcp [::]:9443: use of closed network connection"}
{"L":"DEBUG","T":"230301 024130.568","M":"netLayer.loopAccept, listener got closed","error":"accept tcp [::]:8443: use of closed network connection"}

Other 【其他】
由于超出了Github Issue的长度限制,nginx日志将在下面提供

@HeXis-YS HeXis-YS added the bug Something isn't working label Mar 1, 2023
@HeXis-YS
Copy link
Author

HeXis-YS commented Mar 1, 2023

正常回落nginx error.log
2023/03/01 02:39:42 [debug] 857#857: epoll add event: fd:5 op:1 ev:00002001
2023/03/01 02:39:47 [debug] 857#857: accept on unix:/dev/shm/h2c.sock, ready: 1
2023/03/01 02:39:47 [debug] 857#857: posix_memalign: 000055DF0D58A990:512 @16
2023/03/01 02:39:47 [debug] 857#857: *1 accept: unix: fd:6
2023/03/01 02:39:47 [debug] 857#857: *1 event timer add: 6: 31449600000:31475152422
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 1
2023/03/01 02:39:47 [debug] 857#857: *1 epoll add event: fd:6 op:1 ev:80002001
2023/03/01 02:39:47 [debug] 857#857: accept() not ready (11: Resource temporarily unavailable)
2023/03/01 02:39:47 [debug] 857#857: *1 init http2 connection
2023/03/01 02:39:47 [debug] 857#857: *1 malloc: 000055DF0D5885C0:456
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D59D920:4096 @16
2023/03/01 02:39:47 [debug] 857#857: *1 add cleanup: 000055DF0D58AB18
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D579560:512 @16
2023/03/01 02:39:47 [debug] 857#857: *1 http2 send SETTINGS frame
2023/03/01 02:39:47 [debug] 857#857: *1 http2 send WINDOW_UPDATE frame sid:0, window:2147418112
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 read handler
2023/03/01 02:39:47 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:47 [debug] 857#857: *1 recv: fd:6 148 of 262112
2023/03/01 02:39:47 [debug] 857#857: *1 http2 preface verified
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:4 f:0 l:18 sid:0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 SETTINGS frame
2023/03/01 02:39:47 [debug] 857#857: *1 http2 setting 1:65536
2023/03/01 02:39:47 [debug] 857#857: *1 http2 setting 4:131072
2023/03/01 02:39:47 [debug] 857#857: *1 http2 setting 5:16384
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D473 end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:8 f:0 l:4 sid:0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 WINDOW_UPDATE frame sid:0 window:12517377
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D480 end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:3
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:3 depends on 0 excl:0 weight:201
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D48E end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:5
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:5 depends on 0 excl:0 weight:101
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D49C end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:7
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:7 depends on 0 excl:0 weight:1
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D5756F0:512 @16
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D4AA end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:9
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:9 depends on 7 excl:0 weight:1
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D4B8 end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:11
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:11 depends on 3 excl:0 weight:1
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D4C6 end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:2 f:0 l:5 sid:13
2023/03/01 02:39:47 [debug] 857#857: *1 http2 PRIORITY frame sid:13 depends on 0 excl:0 weight:241
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D4D4 end:000055DF0D68D4D4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D59DAD8 sid:0 bl:0 len:0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D59DA28 sid:0 bl:0 len:4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D59D970 sid:0 bl:0 len:18
2023/03/01 02:39:47 [debug] 857#857: *1 writev: 49 of 49
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D59D970 sid:0 bl:0 len:18
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D59DA28 sid:0 bl:0 len:4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D59DAD8 sid:0 bl:0 len:0
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 1
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D59D920, unused: 3480
2023/03/01 02:39:47 [debug] 857#857: *1 http2 idle handler
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D59D920:4096 @16
2023/03/01 02:39:47 [debug] 857#857: *1 http2 read handler
2023/03/01 02:39:47 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:47 [debug] 857#857: *1 recv: fd:6 348 of 262112
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:1 f:24 l:293 sid:15
2023/03/01 02:39:47 [debug] 857#857: *1 http2 HEADERS frame sid:15 depends on 13 excl:0 weight:42
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D58D1D0:1024 @16
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D58DAC0:512 @16
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D5920D0:4096 @16
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D5930E0:4096 @16
2023/03/01 02:39:47 [debug] 857#857: *1 event timer del: 6: 31475152422
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed header: 3
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: ":method: POST"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 5
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:10
2023/03/01 02:39:47 [debug] 857#857: *1 s:0 in:'2F:/'
2023/03/01 02:39:47 [debug] 857#857: *1 s:1 in:'2E:.'
2023/03/01 02:39:47 [debug] 857#857: *1 s:2 in:'61:a'
2023/03/01 02:39:47 [debug] 857#857: *1 s:0 in:'75:u'
2023/03/01 02:39:47 [debug] 857#857: *1 s:0 in:'74:t'
2023/03/01 02:39:47 [debug] 857#857: *1 s:0 in:'68:h'
2023/03/01 02:39:47 [debug] 857#857: *1 s:0 in:'3F:?'
2023/03/01 02:39:47 [debug] 857#857: *1 http uri: "/.auth"
2023/03/01 02:39:47 [debug] 857#857: *1 http args: "Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http exten: ""
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: ":path: /.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 1
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:14
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: ":authority: 1.2.3.4:8443"
2023/03/01 02:39:47 [debug] 857#857: *1 malloc: 000055DF0D5887D0:512
2023/03/01 02:39:47 [debug] 857#857: *1 malloc: 000055DF0D5940F0:4096
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 61 free:4096
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: ":authority: 1.2.3.4:8443"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed header: 7
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: ":scheme: https"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 58
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:60
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 122 free:4035
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 19
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:3
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "accept: */*"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 41 free:3913
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "accept: */*"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 17
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:48
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 106 free:3872
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 16
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:13
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "accept-encoding: gzip, deflate, br"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 64 free:3766
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 28
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:2
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "content-length: 24"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 48 free:3702
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "content-length: 24"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:5
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:20
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "origin: https://1.2.3.4:8443"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 65 free:3654
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "origin: https://1.2.3.4:8443"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:3
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:1
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "dnt: 1"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 36 free:3589
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "dnt: 1"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 get indexed name: 51
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:20
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "referer: https://1.2.3.4:8443/"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 67 free:3553
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "referer: https://1.2.3.4:8443/"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:10
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:4
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "sec-fetch-dest: empty"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 51 free:3486
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "sec-fetch-dest: empty"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:10
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:3
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "sec-fetch-mode: cors"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 50 free:3435
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "sec-fetch-mode: cors"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:10
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:8
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "sec-fetch-site: same-origin"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 57 free:3385
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "sec-fetch-site: same-origin"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:2
2023/03/01 02:39:47 [debug] 857#857: *1 http2 encoded string, len:6
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table add: "te: trailers"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table account: 42 free:3328
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header: "te: trailers"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 request line: "POST /.auth?Login HTTP/2.0"
2023/03/01 02:39:47 [debug] 857#857: *1 rewrite phase: 0
2023/03/01 02:39:47 [debug] 857#857: *1 test location: "/"
2023/03/01 02:39:47 [debug] 857#857: *1 using configuration "/"
2023/03/01 02:39:47 [debug] 857#857: *1 http cl:24 max:1048576
2023/03/01 02:39:47 [debug] 857#857: *1 rewrite phase: 2
2023/03/01 02:39:47 [debug] 857#857: *1 post rewrite phase: 3
2023/03/01 02:39:47 [debug] 857#857: *1 generic phase: 4
2023/03/01 02:39:47 [debug] 857#857: *1 generic phase: 5
2023/03/01 02:39:47 [debug] 857#857: *1 access phase: 6
2023/03/01 02:39:47 [debug] 857#857: *1 access phase: 7
2023/03/01 02:39:47 [debug] 857#857: *1 post access phase: 8
2023/03/01 02:39:47 [debug] 857#857: *1 generic phase: 9
2023/03/01 02:39:47 [debug] 857#857: *1 generic phase: 10
2023/03/01 02:39:47 [debug] 857#857: *1 http2 send WINDOW_UPDATE frame sid:15, window:2147418111
2023/03/01 02:39:47 [debug] 857#857: *1 event timer add: 6: 60000:25612423
2023/03/01 02:39:47 [debug] 857#857: *1 http finalize request: -4, "/.auth?Login" a:1, c:2
2023/03/01 02:39:47 [debug] 857#857: *1 http request count:2 blk:0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D56E end:000055DF0D68D59C
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:8 f:0 l:4 sid:15
2023/03/01 02:39:47 [debug] 857#857: *1 http2 WINDOW_UPDATE frame sid:15 window:12451840
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D57B end:000055DF0D68D59C
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame type:0 f:1 l:24 sid:15
2023/03/01 02:39:47 [debug] 857#857: *1 http2 DATA frame
2023/03/01 02:39:47 [debug] 857#857: *1 event timer del: 6: 25612423
2023/03/01 02:39:47 [debug] 857#857: *1 http body new buf t:1 f:0 000055DF0D5930A8, pos 000055DF0D5930A8, size: 24 file: 0, size: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http init upstream, client timer: 0
2023/03/01 02:39:47 [debug] 857#857: *1 post event 000055DF0D59DA60
2023/03/01 02:39:47 [debug] 857#857: *1 http script copy: "Host"
2023/03/01 02:39:47 [debug] 857#857: *1 http script var: "127.0.0.1"
2023/03/01 02:39:47 [debug] 857#857: *1 http script copy: "Connection"
2023/03/01 02:39:47 [debug] 857#857: *1 http script copy: "close"
2023/03/01 02:39:47 [debug] 857#857: *1 http script copy: "Content-Length"
2023/03/01 02:39:47 [debug] 857#857: *1 http script var: "24"
2023/03/01 02:39:47 [debug] 857#857: *1 http script copy: ""
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "accept: */*"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "origin: https://1.2.3.4:8443"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "dnt: 1"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "referer: https://1.2.3.4:8443/"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "sec-fetch-dest: empty"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "sec-fetch-mode: cors"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "sec-fetch-site: same-origin"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header:
"POST /.auth?Login HTTP/1.1
Host: 127.0.0.1
Connection: close
Content-Length: 24
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0
accept: */*
accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2
accept-encoding: gzip, deflate, br
origin: https://1.2.3.4:8443
dnt: 1
referer: https://1.2.3.4:8443/
sec-fetch-dest: empty
sec-fetch-mode: cors
sec-fetch-site: same-origin

"
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D595100:4096 @16
2023/03/01 02:39:47 [debug] 857#857: *1 http cleanup add: 000055DF0D5940A8
2023/03/01 02:39:47 [debug] 857#857: *1 get rr peer, try: 1
2023/03/01 02:39:47 [debug] 857#857: *1 stream socket 11
2023/03/01 02:39:47 [debug] 857#857: *1 epoll add connection: fd:11 ev:80002005
2023/03/01 02:39:47 [debug] 857#857: *1 connect to 127.0.0.1:80, fd:11 #2
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream connect: -2
2023/03/01 02:39:47 [debug] 857#857: *1 posix_memalign: 000055DF0D58DE50:128 @16
2023/03/01 02:39:47 [debug] 857#857: *1 event timer add: 11: 60000:25612423
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D59C end:000055DF0D68D59C
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D59DB88 sid:0 bl:0 len:4
2023/03/01 02:39:47 [debug] 857#857: *1 writev: 13 of 13
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D59DB88 sid:0 bl:0 len:4
2023/03/01 02:39:47 [debug] 857#857: *1 delete posted event 000055DF0D59DA60
2023/03/01 02:39:47 [debug] 857#857: *1 http run request: "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream check client, write event:0, "/.auth"
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream request: "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream send request handler
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream send request
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream send request body
2023/03/01 02:39:47 [debug] 857#857: *1 chain writer buf fl:0 s:465
2023/03/01 02:39:47 [debug] 857#857: *1 chain writer buf fl:1 s:24
2023/03/01 02:39:47 [debug] 857#857: *1 chain writer in: 000055DF0D595190
2023/03/01 02:39:47 [debug] 857#857: *1 writev: 489 of 489
2023/03/01 02:39:47 [debug] 857#857: *1 chain writer out: 0000000000000000
2023/03/01 02:39:47 [debug] 857#857: *1 event timer del: 11: 25612423
2023/03/01 02:39:47 [debug] 857#857: *1 event timer add: 11: 60000:25612423
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream request: "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream process header
2023/03/01 02:39:47 [debug] 857#857: *1 malloc: 000055DF0D596110:4096
2023/03/01 02:39:47 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:47 [debug] 857#857: *1 recv: fd:11 94 of 4096
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy status 200 "200 OK"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "Content-Length: 1"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header: "Set-Cookie: u=5Vr2JeYjVqn; Max-Age=99504078; HttpOnly"
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy header done
2023/03/01 02:39:47 [debug] 857#857: *1 http2 header filter
2023/03/01 02:39:47 [debug] 857#857: *1 http2 push resources
2023/03/01 02:39:47 [debug] 857#857: *1 http2 table size update: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 output header: ":status: 200"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 output header: "server: nginx/1.20.2"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 output header: "date: Wed, 01 Mar 2023 02:39:47 GMT"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 output header: "content-length: 1"
2023/03/01 02:39:47 [debug] 857#857: *1 http2 output header: "set-cookie: u=5Vr2JeYjVqn; Max-Age=99504078; HttpOnly"
2023/03/01 02:39:47 [debug] 857#857: *1 http2:15 create HEADERS frame 000055DF0D5954D8: len:82 fin:0
2023/03/01 02:39:47 [debug] 857#857: *1 http cleanup add: 000055DF0D5955C0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D5954D8 sid:15 bl:1 len:82
2023/03/01 02:39:47 [debug] 857#857: *1 writev: 91 of 91
2023/03/01 02:39:47 [debug] 857#857: *1 http2:15 HEADERS frame 000055DF0D5954D8 was sent
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D5954D8 sid:15 bl:1 len:82
2023/03/01 02:39:47 [debug] 857#857: *1 http cacheable: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http proxy filter init s:200 h:0 c:0 l:1
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream process upstream
2023/03/01 02:39:47 [debug] 857#857: *1 pipe read upstream: 0
2023/03/01 02:39:47 [debug] 857#857: *1 pipe preread: 1
2023/03/01 02:39:47 [debug] 857#857: *1 pipe buf free s:0 t:1 f:0 000055DF0D596110, pos 000055DF0D59616D, size: 1 file: 0, size: 0
2023/03/01 02:39:47 [debug] 857#857: *1 pipe length: 1
2023/03/01 02:39:47 [debug] 857#857: *1 input buf #0
2023/03/01 02:39:47 [debug] 857#857: *1 pipe write downstream: 1
2023/03/01 02:39:47 [debug] 857#857: *1 pipe write downstream flush in
2023/03/01 02:39:47 [debug] 857#857: *1 http output filter "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http copy filter: "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http postpone filter "/.auth?Login" 000055DF0D595190
2023/03/01 02:39:47 [debug] 857#857: *1 write new buf t:1 f:0 000055DF0D596110, pos 000055DF0D59616D, size: 1 file: 0, size: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http write filter: l:0 f:0 s:1
2023/03/01 02:39:47 [debug] 857#857: *1 http copy filter: 0 "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 pipe write downstream done
2023/03/01 02:39:47 [debug] 857#857: *1 event timer: 11, old: 25612423, new: 25612423
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream exit: 0000000000000000
2023/03/01 02:39:47 [debug] 857#857: *1 finalize http upstream request: 0
2023/03/01 02:39:47 [debug] 857#857: *1 finalize http proxy request
2023/03/01 02:39:47 [debug] 857#857: *1 free rr peer 1 0
2023/03/01 02:39:47 [debug] 857#857: *1 close http upstream connection: 11
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D58DE50, unused: 48
2023/03/01 02:39:47 [debug] 857#857: *1 event timer del: 11: 25612423
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http upstream temp fd: -1
2023/03/01 02:39:47 [debug] 857#857: *1 http output filter "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http copy filter: "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http postpone filter "/.auth?Login" 00007FFFAE3A0F00
2023/03/01 02:39:47 [debug] 857#857: *1 write old buf t:1 f:0 000055DF0D596110, pos 000055DF0D59616D, size: 1 file: 0, size: 0
2023/03/01 02:39:47 [debug] 857#857: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2023/03/01 02:39:47 [debug] 857#857: *1 http write filter: l:1 f:0 s:1
2023/03/01 02:39:47 [debug] 857#857: *1 http write filter limit 0
2023/03/01 02:39:47 [debug] 857#857: *1 http2:15 windows: conn:12582912 stream:12582912
2023/03/01 02:39:47 [debug] 857#857: *1 http2:15 create DATA frame 000055DF0D5954D8: len:1 flags:1
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame out: 000055DF0D5954D8 sid:15 bl:0 len:1
2023/03/01 02:39:47 [debug] 857#857: *1 writev: 10 of 10
2023/03/01 02:39:47 [debug] 857#857: *1 http2:15 DATA frame 000055DF0D5954D8 was sent
2023/03/01 02:39:47 [debug] 857#857: *1 http2 frame sent: 000055DF0D5954D8 sid:15 bl:0 len:1
2023/03/01 02:39:47 [debug] 857#857: *1 http write filter 0000000000000000
2023/03/01 02:39:47 [debug] 857#857: *1 http copy filter: 0 "/.auth?Login"
2023/03/01 02:39:47 [debug] 857#857: *1 http finalize request: 0, "/.auth?Login" a:1, c:1
2023/03/01 02:39:47 [debug] 857#857: *1 http request count:1 blk:0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 close stream 15, queued 0, processing 1, pushing 0
2023/03/01 02:39:47 [debug] 857#857: *1 http close request
2023/03/01 02:39:47 [debug] 857#857: *1 http log handler
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D596110
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D5920D0, unused: 0
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D5930E0, unused: 0
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D595100, unused: 2016
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D58D1D0, unused: 528
2023/03/01 02:39:47 [debug] 857#857: *1 post event 000055DF0D62D4E0
2023/03/01 02:39:47 [debug] 857#857: *1 delete posted event 000055DF0D62D4E0
2023/03/01 02:39:47 [debug] 857#857: *1 http2 handle connection handler
2023/03/01 02:39:47 [debug] 857#857: *1 event timer add: 6: 31449600000:31475152423
2023/03/01 02:39:47 [debug] 857#857: *1 reusable connection: 1
2023/03/01 02:39:47 [debug] 857#857: *1 free: 000055DF0D59D920, unused: 3304
2023/03/01 02:39:48 [debug] 857#857: *1 http2 idle handler
2023/03/01 02:39:48 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D59D920:4096 @16
2023/03/01 02:39:48 [debug] 857#857: *1 http2 read handler
2023/03/01 02:39:48 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:48 [debug] 857#857: *1 recv: fd:6 9 of 262112
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame type:4 f:1 l:0 sid:0
2023/03/01 02:39:48 [debug] 857#857: *1 http2 SETTINGS frame
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D449 end:000055DF0D68D449
2023/03/01 02:39:48 [debug] 857#857: *1 reusable connection: 1
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D59D920, unused: 4016
2023/03/01 02:39:48 [debug] 857#857: *1 http2 idle handler
2023/03/01 02:39:48 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D59D920:4096 @16
2023/03/01 02:39:48 [debug] 857#857: *1 http2 read handler
2023/03/01 02:39:48 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:48 [debug] 857#857: *1 recv: fd:6 60 of 262112
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame type:1 f:25 l:38 sid:17
2023/03/01 02:39:48 [debug] 857#857: *1 http2 HEADERS frame sid:17 depends on 5 excl:0 weight:22
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D58D1D0:1024 @16
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D587FD0:512 @16
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D5920D0:4096 @16
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D5930E0:4096 @16
2023/03/01 02:39:48 [debug] 857#857: *1 event timer del: 6: 31475152423
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 2
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: ":method: GET"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed name: 5
2023/03/01 02:39:48 [debug] 857#857: *1 http2 encoded string, len:4
2023/03/01 02:39:48 [debug] 857#857: *1 http uri: "/"
2023/03/01 02:39:48 [debug] 857#857: *1 http args: "ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http exten: ""
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: ":path: /?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 74
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: ":authority: 1.2.3.4:8443"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 7
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: ":scheme: https"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 73
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 72
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "accept: */*"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 71
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 70
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 67
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "dnt: 1"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 66
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "referer: https://1.2.3.4:8443/"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed name: 32
2023/03/01 02:39:48 [debug] 857#857: *1 http2 encoded string, len:11
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "cookie: u=5Vr2JeYjVqn"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 65
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "sec-fetch-dest: empty"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 64
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "sec-fetch-mode: cors"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 63
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "sec-fetch-site: same-origin"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 get indexed header: 62
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header: "te: trailers"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 request line: "GET /?ls HTTP/2.0"
2023/03/01 02:39:48 [debug] 857#857: *1 rewrite phase: 0
2023/03/01 02:39:48 [debug] 857#857: *1 test location: "/"
2023/03/01 02:39:48 [debug] 857#857: *1 using configuration "/"
2023/03/01 02:39:48 [debug] 857#857: *1 http cl:-1 max:1048576
2023/03/01 02:39:48 [debug] 857#857: *1 rewrite phase: 2
2023/03/01 02:39:48 [debug] 857#857: *1 post rewrite phase: 3
2023/03/01 02:39:48 [debug] 857#857: *1 generic phase: 4
2023/03/01 02:39:48 [debug] 857#857: *1 generic phase: 5
2023/03/01 02:39:48 [debug] 857#857: *1 access phase: 6
2023/03/01 02:39:48 [debug] 857#857: *1 access phase: 7
2023/03/01 02:39:48 [debug] 857#857: *1 post access phase: 8
2023/03/01 02:39:48 [debug] 857#857: *1 generic phase: 9
2023/03/01 02:39:48 [debug] 857#857: *1 generic phase: 10
2023/03/01 02:39:48 [debug] 857#857: *1 http init upstream, client timer: 0
2023/03/01 02:39:48 [debug] 857#857: *1 post event 000055DF0D59DA60
2023/03/01 02:39:48 [debug] 857#857: *1 http script copy: "Host"
2023/03/01 02:39:48 [debug] 857#857: *1 http script var: "127.0.0.1"
2023/03/01 02:39:48 [debug] 857#857: *1 http script copy: "Connection"
2023/03/01 02:39:48 [debug] 857#857: *1 http script copy: "close"
2023/03/01 02:39:48 [debug] 857#857: *1 http script copy: ""
2023/03/01 02:39:48 [debug] 857#857: *1 http script copy: ""
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "accept: */*"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "dnt: 1"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "referer: https://1.2.3.4:8443/"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "sec-fetch-dest: empty"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "sec-fetch-mode: cors"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "sec-fetch-site: same-origin"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "cookie: u=5Vr2JeYjVqn"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header:
"GET /?ls HTTP/1.1
Host: 127.0.0.1
Connection: close
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0
accept: */*
accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2
accept-encoding: gzip, deflate, br
dnt: 1
referer: https://1.2.3.4:8443/
sec-fetch-dest: empty
sec-fetch-mode: cors
sec-fetch-site: same-origin
cookie: u=5Vr2JeYjVqn

"
2023/03/01 02:39:48 [debug] 857#857: *1 http cleanup add: 000055DF0D5930B8
2023/03/01 02:39:48 [debug] 857#857: *1 get rr peer, try: 1
2023/03/01 02:39:48 [debug] 857#857: *1 stream socket 11
2023/03/01 02:39:48 [debug] 857#857: *1 epoll add connection: fd:11 ev:80002005
2023/03/01 02:39:48 [debug] 857#857: *1 connect to 127.0.0.1:80, fd:11 #3
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream connect: -2
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D58DE50:128 @16
2023/03/01 02:39:48 [debug] 857#857: *1 event timer add: 11: 60000:25612770
2023/03/01 02:39:48 [debug] 857#857: *1 http finalize request: -4, "/?ls" a:1, c:2
2023/03/01 02:39:48 [debug] 857#857: *1 http request count:2 blk:0
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D46F end:000055DF0D68D47C
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame type:8 f:0 l:4 sid:17
2023/03/01 02:39:48 [debug] 857#857: *1 http2 WINDOW_UPDATE frame sid:17 window:12451840
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame complete pos:000055DF0D68D47C end:000055DF0D68D47C
2023/03/01 02:39:48 [debug] 857#857: *1 delete posted event 000055DF0D59DA60
2023/03/01 02:39:48 [debug] 857#857: *1 http run request: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream check client, write event:0, "/"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream request: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream send request handler
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream send request
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream send request body
2023/03/01 02:39:48 [debug] 857#857: *1 chain writer buf fl:1 s:422
2023/03/01 02:39:48 [debug] 857#857: *1 chain writer in: 000055DF0D593FF8
2023/03/01 02:39:48 [debug] 857#857: *1 writev: 422 of 422
2023/03/01 02:39:48 [debug] 857#857: *1 chain writer out: 0000000000000000
2023/03/01 02:39:48 [debug] 857#857: *1 event timer del: 11: 25612770
2023/03/01 02:39:48 [debug] 857#857: *1 event timer add: 11: 60000:25612771
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream request: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream process header
2023/03/01 02:39:48 [debug] 857#857: *1 malloc: 000055DF0D595100:4096
2023/03/01 02:39:48 [debug] 857#857: *1 posix_memalign: 000055DF0D596110:4096 @16
2023/03/01 02:39:48 [debug] 857#857: *1 recv: eof:0, avail:-1
2023/03/01 02:39:48 [debug] 857#857: *1 recv: fd:11 110 of 4096
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy status 200 "200 OK"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "Content-Length: 729"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "Expires: -1"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "Etag: dmpodgjh"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header: "Content-Type: text/plain; charset=utf-8"
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy header done
2023/03/01 02:39:48 [debug] 857#857: *1 http2 header filter
2023/03/01 02:39:48 [debug] 857#857: *1 http2 push resources
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: ":status: 200"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "server: nginx/1.20.2"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "date: Wed, 01 Mar 2023 02:39:48 GMT"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "content-type: text/plain; charset=utf-8"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "content-length: 729"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "expires: -1"
2023/03/01 02:39:48 [debug] 857#857: *1 http2 output header: "etag: dmpodgjh"
2023/03/01 02:39:48 [debug] 857#857: *1 http2:17 create HEADERS frame 000055DF0D5963D0: len:83 fin:0
2023/03/01 02:39:48 [debug] 857#857: *1 http cleanup add: 000055DF0D5964B8
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame out: 000055DF0D5963D0 sid:17 bl:1 len:83
2023/03/01 02:39:48 [debug] 857#857: *1 writev: 92 of 92
2023/03/01 02:39:48 [debug] 857#857: *1 http2:17 HEADERS frame 000055DF0D5963D0 was sent
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame sent: 000055DF0D5963D0 sid:17 bl:1 len:83
2023/03/01 02:39:48 [debug] 857#857: *1 http cacheable: 0
2023/03/01 02:39:48 [debug] 857#857: *1 http proxy filter init s:200 h:0 c:0 l:729
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream process upstream
2023/03/01 02:39:48 [debug] 857#857: *1 pipe read upstream: 0
2023/03/01 02:39:48 [debug] 857#857: *1 pipe preread: 0
2023/03/01 02:39:48 [debug] 857#857: *1 pipe buf free s:0 t:1 f:0 000055DF0D595100, pos 000055DF0D59516E, size: 0 file: 0, size: 0
2023/03/01 02:39:48 [debug] 857#857: *1 pipe length: 729
2023/03/01 02:39:48 [debug] 857#857: *1 event timer: 11, old: 25612771, new: 25612772
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream request: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream dummy handler
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream request: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream process upstream
2023/03/01 02:39:48 [debug] 857#857: *1 pipe read upstream: 1
2023/03/01 02:39:48 [debug] 857#857: *1 readv: eof:0, avail:-1
2023/03/01 02:39:48 [debug] 857#857: *1 readv: 1, last:3986
2023/03/01 02:39:48 [debug] 857#857: *1 pipe recv chain: 729
2023/03/01 02:39:48 [debug] 857#857: *1 pipe buf free s:0 t:1 f:0 000055DF0D595100, pos 000055DF0D59516E, size: 729 file: 0, size: 0
2023/03/01 02:39:48 [debug] 857#857: *1 pipe length: 729
2023/03/01 02:39:48 [debug] 857#857: *1 input buf #0
2023/03/01 02:39:48 [debug] 857#857: *1 pipe write downstream: 1
2023/03/01 02:39:48 [debug] 857#857: *1 pipe write downstream flush in
2023/03/01 02:39:48 [debug] 857#857: *1 http output filter "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http copy filter: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http postpone filter "/?ls" 000055DF0D5965F8
2023/03/01 02:39:48 [debug] 857#857: *1 write new buf t:1 f:0 000055DF0D595100, pos 000055DF0D59516E, size: 729 file: 0, size: 0
2023/03/01 02:39:48 [debug] 857#857: *1 http write filter: l:0 f:0 s:729
2023/03/01 02:39:48 [debug] 857#857: *1 http copy filter: 0 "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 pipe write downstream done
2023/03/01 02:39:48 [debug] 857#857: *1 event timer: 11, old: 25612771, new: 25612772
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream exit: 0000000000000000
2023/03/01 02:39:48 [debug] 857#857: *1 finalize http upstream request: 0
2023/03/01 02:39:48 [debug] 857#857: *1 finalize http proxy request
2023/03/01 02:39:48 [debug] 857#857: *1 free rr peer 1 0
2023/03/01 02:39:48 [debug] 857#857: *1 close http upstream connection: 11
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D58DE50, unused: 48
2023/03/01 02:39:48 [debug] 857#857: *1 event timer del: 11: 25612771
2023/03/01 02:39:48 [debug] 857#857: *1 reusable connection: 0
2023/03/01 02:39:48 [debug] 857#857: *1 http upstream temp fd: -1
2023/03/01 02:39:48 [debug] 857#857: *1 http output filter "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http copy filter: "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http postpone filter "/?ls" 00007FFFAE3A0F00
2023/03/01 02:39:48 [debug] 857#857: *1 write old buf t:1 f:0 000055DF0D595100, pos 000055DF0D59516E, size: 729 file: 0, size: 0
2023/03/01 02:39:48 [debug] 857#857: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2023/03/01 02:39:48 [debug] 857#857: *1 http write filter: l:1 f:0 s:729
2023/03/01 02:39:48 [debug] 857#857: *1 http write filter limit 0
2023/03/01 02:39:48 [debug] 857#857: *1 http2:17 windows: conn:12582911 stream:12582912
2023/03/01 02:39:48 [debug] 857#857: *1 http2:17 create DATA frame 000055DF0D5963D0: len:729 flags:1
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame out: 000055DF0D5963D0 sid:17 bl:0 len:729
2023/03/01 02:39:48 [debug] 857#857: *1 writev: 738 of 738
2023/03/01 02:39:48 [debug] 857#857: *1 http2:17 DATA frame 000055DF0D5963D0 was sent
2023/03/01 02:39:48 [debug] 857#857: *1 http2 frame sent: 000055DF0D5963D0 sid:17 bl:0 len:729
2023/03/01 02:39:48 [debug] 857#857: *1 http write filter 0000000000000000
2023/03/01 02:39:48 [debug] 857#857: *1 http copy filter: 0 "/?ls"
2023/03/01 02:39:48 [debug] 857#857: *1 http finalize request: 0, "/?ls" a:1, c:1
2023/03/01 02:39:48 [debug] 857#857: *1 http request count:1 blk:0
2023/03/01 02:39:48 [debug] 857#857: *1 http2 close stream 17, queued 0, processing 1, pushing 0
2023/03/01 02:39:48 [debug] 857#857: *1 http close request
2023/03/01 02:39:48 [debug] 857#857: *1 http log handler
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D595100
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D5920D0, unused: 0
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D5930E0, unused: 15
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D596110, unused: 2273
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D58D1D0, unused: 552
2023/03/01 02:39:48 [debug] 857#857: *1 post event 000055DF0D62D4E0
2023/03/01 02:39:48 [debug] 857#857: *1 delete posted event 000055DF0D62D4E0
2023/03/01 02:39:48 [debug] 857#857: *1 http2 handle connection handler
2023/03/01 02:39:48 [debug] 857#857: *1 event timer add: 6: 31449600000:31475152772
2023/03/01 02:39:48 [debug] 857#857: *1 reusable connection: 1
2023/03/01 02:39:48 [debug] 857#857: *1 free: 000055DF0D59D920, unused: 3480
异常回落nginx error.log
2023/03/01 02:41:18 [debug] 888#888: epoll add event: fd:5 op:1 ev:00002001
2023/03/01 02:41:24 [debug] 888#888: accept on unix:/dev/shm/h2c.sock, ready: 1
2023/03/01 02:41:24 [debug] 888#888: posix_memalign: 00005589039FB990:512 @16
2023/03/01 02:41:24 [debug] 888#888: *1 accept: unix: fd:6
2023/03/01 02:41:24 [debug] 888#888: *1 event timer add: 6: 31449600000:31475249089
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 1
2023/03/01 02:41:24 [debug] 888#888: *1 epoll add event: fd:6 op:1 ev:80002001
2023/03/01 02:41:24 [debug] 888#888: accept() not ready (11: Resource temporarily unavailable)
2023/03/01 02:41:24 [debug] 888#888: *1 init http2 connection
2023/03/01 02:41:24 [debug] 888#888: *1 malloc: 00005589039F95C0:456
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 0000558903A0E920:4096 @16
2023/03/01 02:41:24 [debug] 888#888: *1 add cleanup: 00005589039FBB18
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 00005589039EA560:512 @16
2023/03/01 02:41:24 [debug] 888#888: *1 http2 send SETTINGS frame
2023/03/01 02:41:24 [debug] 888#888: *1 http2 send WINDOW_UPDATE frame sid:0, window:2147418112
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 read handler
2023/03/01 02:41:24 [debug] 888#888: *1 recv: eof:0, avail:-1
2023/03/01 02:41:24 [debug] 888#888: *1 recv: fd:6 64 of 262112
2023/03/01 02:41:24 [debug] 888#888: *1 http2 preface verified
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame type:4 f:0 l:18 sid:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 SETTINGS frame
2023/03/01 02:41:24 [debug] 888#888: *1 http2 setting 2:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 setting 4:4194304
2023/03/01 02:41:24 [debug] 888#888: *1 http2 setting 6:10485760
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame complete pos:0000558903AFE473 end:0000558903AFE480
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame type:8 f:0 l:4 sid:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 WINDOW_UPDATE frame sid:0 window:1073741824
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame complete pos:0000558903AFE480 end:0000558903AFE480
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame out: 0000558903A0EAD8 sid:0 bl:0 len:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame out: 0000558903A0EA28 sid:0 bl:0 len:4
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame out: 0000558903A0E970 sid:0 bl:0 len:18
2023/03/01 02:41:24 [debug] 888#888: *1 writev: 49 of 49
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame sent: 0000558903A0E970 sid:0 bl:0 len:18
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame sent: 0000558903A0EA28 sid:0 bl:0 len:4
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame sent: 0000558903A0EAD8 sid:0 bl:0 len:0
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 1
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A0E920, unused: 3480
2023/03/01 02:41:24 [debug] 888#888: *1 http2 idle handler
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 0
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 0000558903A0E920:4096 @16
2023/03/01 02:41:24 [debug] 888#888: *1 http2 read handler
2023/03/01 02:41:24 [debug] 888#888: *1 recv: eof:0, avail:-1
2023/03/01 02:41:24 [debug] 888#888: *1 recv: fd:6 305 of 262112
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame type:1 f:4 l:296 sid:3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 HEADERS frame sid:3 depends on 0 excl:0 weight:16
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 00005589039FE1D0:1024 @16
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 0000558903A030D0:4096 @16
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 0000558903A040E0:4096 @16
2023/03/01 02:41:24 [debug] 888#888: *1 event timer del: 6: 31475249089
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 1
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:14
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: ":authority: 1.2.3.4:9443"
2023/03/01 02:41:24 [debug] 888#888: *1 malloc: 00005589039E66F0:512
2023/03/01 02:41:24 [debug] 888#888: *1 malloc: 0000558903A050F0:4096
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 61 free:4096
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: ":authority: 1.2.3.4:9443"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed header: 3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: ":method: POST"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 5
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:5
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: ":path: /.auth"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 43 free:4035
2023/03/01 02:41:24 [debug] 888#888: *1 s:0 in:'2F:/'
2023/03/01 02:41:24 [debug] 888#888: *1 s:1 in:'2E:.'
2023/03/01 02:41:24 [debug] 888#888: *1 s:2 in:'61:a'
2023/03/01 02:41:24 [debug] 888#888: *1 s:0 in:'75:u'
2023/03/01 02:41:24 [debug] 888#888: *1 s:0 in:'74:t'
2023/03/01 02:41:24 [debug] 888#888: *1 s:0 in:'68:h'
2023/03/01 02:41:24 [debug] 888#888: *1 http uri: "/.auth"
2023/03/01 02:41:24 [debug] 888#888: *1 http args: ""
2023/03/01 02:41:24 [debug] 888#888: *1 http exten: ""
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: ":path: /.auth"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed header: 6
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: ":scheme: http"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:10
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "sec-fetch-mode: cors"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 50 free:3992
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "sec-fetch-mode: cors"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 17
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:48
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 106 free:3942
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 16
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:13
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "accept-encoding: gzip, deflate, br"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 64 free:3836
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:5
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:20
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "origin: https://1.2.3.4:9443"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 65 free:3772
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 00005589039FEAC0:512 @16
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "origin: https://1.2.3.4:9443"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 raw string, len:3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 raw string, len:1
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "dnt: 1"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 36 free:3707
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "dnt: 1"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 51
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:20
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "referer: https://1.2.3.4:9443/"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 67 free:3671
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "referer: https://1.2.3.4:9443/"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:10
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:4
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "sec-fetch-dest: empty"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 51 free:3604
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "sec-fetch-dest: empty"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:10
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:8
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "sec-fetch-site: same-origin"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 57 free:3553
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "sec-fetch-site: same-origin"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 58
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:60
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 122 free:3496
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 19
2023/03/01 02:41:24 [debug] 888#888: *1 http2 raw string, len:3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "accept: */*"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 41 free:3374
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "accept: */*"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 32
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:11
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "cookie: u=5Vr2JeYjVqn"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 51 free:3333
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "cookie: u=5Vr2JeYjVqn"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 raw string, len:2
2023/03/01 02:41:24 [debug] 888#888: *1 http2 encoded string, len:6
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "te: trailers"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 42 free:3282
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "te: trailers"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 get indexed name: 28
2023/03/01 02:41:24 [debug] 888#888: *1 http2 raw string, len:2
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table add: "content-length: 24"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 table account: 48 free:3240
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header: "content-length: 24"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 request line: "POST /.auth HTTP/2.0"
2023/03/01 02:41:24 [debug] 888#888: *1 rewrite phase: 0
2023/03/01 02:41:24 [debug] 888#888: *1 test location: "/"
2023/03/01 02:41:24 [debug] 888#888: *1 using configuration "/"
2023/03/01 02:41:24 [debug] 888#888: *1 http cl:24 max:1048576
2023/03/01 02:41:24 [debug] 888#888: *1 rewrite phase: 2
2023/03/01 02:41:24 [debug] 888#888: *1 post rewrite phase: 3
2023/03/01 02:41:24 [debug] 888#888: *1 generic phase: 4
2023/03/01 02:41:24 [debug] 888#888: *1 generic phase: 5
2023/03/01 02:41:24 [debug] 888#888: *1 access phase: 6
2023/03/01 02:41:24 [debug] 888#888: *1 access phase: 7
2023/03/01 02:41:24 [debug] 888#888: *1 post access phase: 8
2023/03/01 02:41:24 [debug] 888#888: *1 generic phase: 9
2023/03/01 02:41:24 [debug] 888#888: *1 generic phase: 10
2023/03/01 02:41:24 [debug] 888#888: *1 http2 send WINDOW_UPDATE frame sid:3, window:2147418111
2023/03/01 02:41:24 [debug] 888#888: *1 event timer add: 6: 60000:25709091
2023/03/01 02:41:24 [debug] 888#888: *1 http finalize request: -4, "/.auth?" a:1, c:2
2023/03/01 02:41:24 [debug] 888#888: *1 http request count:2 blk:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame complete pos:0000558903AFE571 end:0000558903AFE571
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame out: 0000558903A0EB88 sid:0 bl:0 len:4
2023/03/01 02:41:24 [debug] 888#888: *1 writev: 13 of 13
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame sent: 0000558903A0EB88 sid:0 bl:0 len:4
2023/03/01 02:41:24 [debug] 888#888: *1 http2 read handler
2023/03/01 02:41:24 [debug] 888#888: *1 recv: eof:0, avail:-1
2023/03/01 02:41:24 [debug] 888#888: *1 recv: fd:6 42 of 262112
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame type:0 f:1 l:24 sid:3
2023/03/01 02:41:24 [debug] 888#888: *1 http2 DATA frame
2023/03/01 02:41:24 [debug] 888#888: *1 event timer del: 6: 25709091
2023/03/01 02:41:24 [debug] 888#888: *1 http body new buf t:1 f:0 0000558903A040B8, pos 0000558903A040B8, size: 24 file: 0, size: 0
2023/03/01 02:41:24 [debug] 888#888: *1 http init upstream, client timer: 0
2023/03/01 02:41:24 [debug] 888#888: *1 post event 0000558903A0EA60
2023/03/01 02:41:24 [debug] 888#888: *1 http script copy: "Host"
2023/03/01 02:41:24 [debug] 888#888: *1 http script var: "127.0.0.1"
2023/03/01 02:41:24 [debug] 888#888: *1 http script copy: "Connection"
2023/03/01 02:41:24 [debug] 888#888: *1 http script copy: "close"
2023/03/01 02:41:24 [debug] 888#888: *1 http script copy: "Content-Length"
2023/03/01 02:41:24 [debug] 888#888: *1 http script var: "24"
2023/03/01 02:41:24 [debug] 888#888: *1 http script copy: ""
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "sec-fetch-mode: cors"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "accept-encoding: gzip, deflate, br"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "origin: https://1.2.3.4:9443"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "dnt: 1"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "referer: https://1.2.3.4:9443/"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "sec-fetch-dest: empty"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "sec-fetch-site: same-origin"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "accept: */*"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "cookie: u=5Vr2JeYjVqn"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header:
"POST /.auth HTTP/1.1
Host: 127.0.0.1
Connection: close
Content-Length: 24
sec-fetch-mode: cors
accept-language: zh-CN,zh;q=0.8,zh-TW;q=0.7,zh-HK;q=0.5,en-US;q=0.3,en;q=0.2
accept-encoding: gzip, deflate, br
origin: https://1.2.3.4:9443
dnt: 1
referer: https://1.2.3.4:9443/
sec-fetch-dest: empty
sec-fetch-site: same-origin
user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/110.0
accept: */*
cookie: u=5Vr2JeYjVqn

"
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 0000558903A06100:4096 @16
2023/03/01 02:41:24 [debug] 888#888: *1 http cleanup add: 0000558903A061A0
2023/03/01 02:41:24 [debug] 888#888: *1 get rr peer, try: 1
2023/03/01 02:41:24 [debug] 888#888: *1 stream socket 11
2023/03/01 02:41:24 [debug] 888#888: *1 epoll add connection: fd:11 ev:80002005
2023/03/01 02:41:24 [debug] 888#888: *1 connect to 127.0.0.1:80, fd:11 #2
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream connect: -2
2023/03/01 02:41:24 [debug] 888#888: *1 posix_memalign: 00005589039FEE50:128 @16
2023/03/01 02:41:24 [debug] 888#888: *1 event timer add: 11: 60000:25709092
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame complete pos:0000558903AFE461 end:0000558903AFE46A
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame type:4 f:1 l:0 sid:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 SETTINGS frame
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame complete pos:0000558903AFE46A end:0000558903AFE46A
2023/03/01 02:41:24 [debug] 888#888: *1 delete posted event 0000558903A0EA60
2023/03/01 02:41:24 [debug] 888#888: *1 http run request: "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream check client, write event:0, "/.auth"
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream request: "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream send request handler
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream send request
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream send request body
2023/03/01 02:41:24 [debug] 888#888: *1 chain writer buf fl:0 s:482
2023/03/01 02:41:24 [debug] 888#888: *1 chain writer buf fl:1 s:24
2023/03/01 02:41:24 [debug] 888#888: *1 chain writer in: 0000558903A06200
2023/03/01 02:41:24 [debug] 888#888: *1 writev: 506 of 506
2023/03/01 02:41:24 [debug] 888#888: *1 chain writer out: 0000000000000000
2023/03/01 02:41:24 [debug] 888#888: *1 event timer del: 11: 25709092
2023/03/01 02:41:24 [debug] 888#888: *1 event timer add: 11: 60000:25709093
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream request: "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream process header
2023/03/01 02:41:24 [debug] 888#888: *1 malloc: 0000558903A07110:4096
2023/03/01 02:41:24 [debug] 888#888: *1 recv: eof:0, avail:-1
2023/03/01 02:41:24 [debug] 888#888: *1 recv: fd:11 48 of 4096
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy status 500 "500 Server Error"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header: "Content-Length: 0"
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy header done
2023/03/01 02:41:24 [debug] 888#888: *1 http2 header filter
2023/03/01 02:41:24 [debug] 888#888: *1 http2 output header: ":status: 500"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 output header: "server: nginx/1.20.2"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 output header: "date: Wed, 01 Mar 2023 02:41:24 GMT"
2023/03/01 02:41:24 [debug] 888#888: *1 http2 output header: "content-length: 0"
2023/03/01 02:41:24 [debug] 888#888: *1 http2:3 create HEADERS frame 0000558903A064C8: len:39 fin:1
2023/03/01 02:41:24 [debug] 888#888: *1 http cleanup add: 0000558903A065B0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame out: 0000558903A064C8 sid:3 bl:1 len:39
2023/03/01 02:41:24 [debug] 888#888: *1 writev: 48 of 48
2023/03/01 02:41:24 [debug] 888#888: *1 http2:3 HEADERS frame 0000558903A064C8 was sent
2023/03/01 02:41:24 [debug] 888#888: *1 http2 frame sent: 0000558903A064C8 sid:3 bl:1 len:39
2023/03/01 02:41:24 [debug] 888#888: *1 http cacheable: 0
2023/03/01 02:41:24 [debug] 888#888: *1 http proxy filter init s:500 h:0 c:0 l:0
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream process upstream
2023/03/01 02:41:24 [debug] 888#888: *1 pipe read upstream: 0
2023/03/01 02:41:24 [debug] 888#888: *1 pipe preread: 0
2023/03/01 02:41:24 [debug] 888#888: *1 pipe buf free s:0 t:1 f:0 0000558903A07110, pos 0000558903A07140, size: 0 file: 0, size: 0
2023/03/01 02:41:24 [debug] 888#888: *1 pipe length: 0
2023/03/01 02:41:24 [debug] 888#888: *1 pipe write downstream: 1
2023/03/01 02:41:24 [debug] 888#888: *1 pipe write downstream done
2023/03/01 02:41:24 [debug] 888#888: *1 event timer: 11, old: 25709093, new: 25709093
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream exit: 0000000000000000
2023/03/01 02:41:24 [debug] 888#888: *1 finalize http upstream request: 0
2023/03/01 02:41:24 [debug] 888#888: *1 finalize http proxy request
2023/03/01 02:41:24 [debug] 888#888: *1 free rr peer 1 0
2023/03/01 02:41:24 [debug] 888#888: *1 close http upstream connection: 11
2023/03/01 02:41:24 [debug] 888#888: *1 free: 00005589039FEE50, unused: 48
2023/03/01 02:41:24 [debug] 888#888: *1 event timer del: 11: 25709093
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 0
2023/03/01 02:41:24 [debug] 888#888: *1 http upstream temp fd: -1
2023/03/01 02:41:24 [debug] 888#888: *1 http output filter "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http copy filter: "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http postpone filter "/.auth?" 00007FFDCCDCDEB0
2023/03/01 02:41:24 [debug] 888#888: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2023/03/01 02:41:24 [debug] 888#888: *1 http write filter: l:1 f:0 s:0
2023/03/01 02:41:24 [debug] 888#888: *1 http write filter limit 0
2023/03/01 02:41:24 [debug] 888#888: *1 http write filter 0000000000000000
2023/03/01 02:41:24 [debug] 888#888: *1 http copy filter: 0 "/.auth?"
2023/03/01 02:41:24 [debug] 888#888: *1 http finalize request: 0, "/.auth?" a:1, c:1
2023/03/01 02:41:24 [debug] 888#888: *1 http request count:1 blk:0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 close stream 3, queued 0, processing 1, pushing 0
2023/03/01 02:41:24 [debug] 888#888: *1 http close request
2023/03/01 02:41:24 [debug] 888#888: *1 http log handler
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A07110
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A030D0, unused: 0
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A040E0, unused: 8
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A06100, unused: 2166
2023/03/01 02:41:24 [debug] 888#888: *1 free: 00005589039FE1D0, unused: 522
2023/03/01 02:41:24 [debug] 888#888: *1 post event 0000558903A9E4E0
2023/03/01 02:41:24 [debug] 888#888: *1 delete posted event 0000558903A9E4E0
2023/03/01 02:41:24 [debug] 888#888: *1 http2 handle connection handler
2023/03/01 02:41:24 [debug] 888#888: *1 event timer add: 6: 31449600000:31475249093
2023/03/01 02:41:24 [debug] 888#888: *1 reusable connection: 1
2023/03/01 02:41:24 [debug] 888#888: *1 free: 0000558903A0E920, unused: 3304
2023/03/01 02:41:30 [debug] 888#888: *1 http2 idle handler
2023/03/01 02:41:30 [debug] 888#888: *1 reusable connection: 0
2023/03/01 02:41:30 [debug] 888#888: *1 posix_memalign: 0000558903A0E920:4096 @16
2023/03/01 02:41:30 [debug] 888#888: *1 http2 read handler
2023/03/01 02:41:30 [debug] 888#888: *1 recv: eof:1, avail:-1
2023/03/01 02:41:30 [debug] 888#888: *1 recv: fd:6 0 of 262112
2023/03/01 02:41:30 [debug] 888#888: *1 close http connection: 6
2023/03/01 02:41:30 [debug] 888#888: *1 event timer del: 6: 31475249093
2023/03/01 02:41:30 [debug] 888#888: *1 reusable connection: 0
2023/03/01 02:41:30 [debug] 888#888: *1 run cleanup: 00005589039FBB18
2023/03/01 02:41:30 [debug] 888#888: *1 free: 0000558903A0E920, unused: 4016
2023/03/01 02:41:30 [debug] 888#888: *1 free: 0000558903A050F0
2023/03/01 02:41:30 [debug] 888#888: *1 free: 00005589039E66F0
2023/03/01 02:41:30 [debug] 888#888: *1 free: 00005589039F95C0
2023/03/01 02:41:30 [debug] 888#888: *1 free: 00005589039FB990, unused: 0
2023/03/01 02:41:30 [debug] 888#888: *1 free: 00005589039EA560, unused: 24
2023/03/01 02:41:30 [debug] 888#888: *1 free: 00005589039FEAC0, unused: 160

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant