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

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

Open HeXis-YS opened this issue 1 year ago • 1 comments

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 1088b279ef77e4c34405ead8913588aaa83f425e 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日志将在下面提供

Mar 01 '23 03:03 HeXis-YS

正常回落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

Mar 01 '23 03:03 HeXis-YS

v2ray_simple v2ray_simple copied to clipboard

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

v2ray_simple
v2ray_simple copied to clipboard