nginx debug log

nginx.log

2019/11/15 09:52:12 [debug] 17657#0: *44 http keepalive handler
2019/11/15 09:52:12 [debug] 17657#0: *44 malloc: 000000000088B310:1024
2019/11/15 09:52:12 [debug] 17657#0: *44 recv: fd:62 -1 of 1024
2019/11/15 09:52:12 [debug] 17657#0: *44 recv() not ready (11: Resource temporarily unavailable)
2019/11/15 09:52:12 [debug] 17657#0: *44 free: 000000000088B310
2019/11/15 09:52:13 [debug] 17657#0: *44 http keepalive handler
2019/11/15 09:52:13 [debug] 17657#0: *44 malloc: 0000000000915720:1024
2019/11/15 09:52:13 [debug] 17657#0: *44 recv: fd:62 1024 of 1024
2019/11/15 09:52:13 [debug] 17657#0: *44 reusable connection: 0
2019/11/15 09:52:13 [debug] 17657#0: *44 posix_memalign: 000000000088A0E0:4096 @16
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Host: xxxxxx.com"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Accept-Encoding: gzip"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "CF-IPCountry: MA"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "CF-RAY: 53601126ed8a612b-BCN"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "X-Forwarded-Proto: http"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "CF-Visitor: {"scheme":"http"}"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Cache-Control: max-age=0"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Upgrade-Insecure-Requests: 1"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/78.0.3904.87 Safari/537.36"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Accept-Language: en-US,en;q=0.9,ar;q=0.8,fr;q=0.7"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "Cookie: XXXXX"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "CF-Connecting-IP: xxx.xxx.xxx.xx"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "CDN-Loop: cloudflare"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "X-Forwarded-For: xxx.xx..xxx.xx"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header: "X-Varnish: 592245"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http header done
2019/11/15 10:06:04 [debug] 17660#0: *5487 event timer del: 000000000091C438: 1573808824069
2019/11/15 10:06:04 [debug] 17660#0: *5487 generic phase: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 add cleanup: 0000000000796B28
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 1
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 2
2019/11/15 10:06:04 [debug] 17660#0: *5487 test location: "/"
2019/11/15 10:06:04 [debug] 17660#0: *5487 using configuration "/"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http cl:-1 max:1048576
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 4
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 5
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 6
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 7
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua rewrite handler, uri:"/" c:1
2019/11/15 10:06:04 [debug] 17660#0: *5487 add cleanup: 0000000000796B68
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua creating new vm state
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua initializing lua registry
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua initializing lua globals
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua initialize the global Lua VM 000000004075C378
2019/11/15 10:06:04 [debug] 17660#0: *5487 malloc: 0000000000A549B0:16
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua creating new thread
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua reset ctx
2019/11/15 10:06:04 [debug] 17660#0: *5487 http cleanup add: 0000000000796BB0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua run thread, top:0 c:1
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket pool get keepalive peer
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket keepalive connection pool not found
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket connect timeout: 500
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket network address given directly
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket resolve retval handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 socket 54
2019/11/15 10:06:04 [debug] 17660#0: *5487 epoll add connection: fd:54 ev:80002005
2019/11/15 10:06:04 [debug] 17660#0: *5487 connect to 127.0.0.1:0, fd:54 #5488
2019/11/15 10:06:04 [debug] 17660#0: *5487 http cleanup add: 000000000088A5D0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket connect: -2
2019/11/15 10:06:04 [debug] 17660#0: *5487 posix_memalign: 0000000000A38D10:128 @16
2019/11/15 10:06:04 [debug] 17660#0: *5487 event timer add: 000000000091C798: 500:1573808764569
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua resume returned 1
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua thread yielded
2019/11/15 10:06:04 [debug] 17660#0: *5487 post event 00000000009882D8
2019/11/15 10:06:04 [debug] 17660#0: *5487 post event 00000000009BC2E8
2019/11/15 10:06:04 [debug] 17660#0: *5487 delete posted event 00000000009882D8
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket handler for "/?", wev 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 event timer del: 000000000091C798: 1573808764569
2019/11/15 10:06:04 [error] 17660#0: *5487 connect() failed (111: Connection refused), client: 196.65.94.64, server: xxxxxx.com, request: "GET / HTTP/1.1", host: "xxxxxx.com"
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket handle connect error
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua finalize socket
2019/11/15 10:06:04 [debug] 17660#0: *5487 delete posted event 00000000009BC2E8
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua close socket connection
2019/11/15 10:06:04 [debug] 17660#0: *5487 free: 0000000000A38D10, unused: 48
2019/11/15 10:06:04 [debug] 17660#0: *5487 reusable connection: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket waking up the current request
2019/11/15 10:06:04 [debug] 17660#0: *5487 rewrite phase: 7
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua rewrite handler, uri:"/" c:1
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp operation done, resuming lua thread
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket calling prepare retvals handler 00000000004CBA80, u:000000004076D1B0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua tcp socket error retval handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua finalize socket
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua run thread, top:0 c:1
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua allocate new chainlink and new buf of size 44, cl:0000000000796C90
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua say response
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua capture header filter, uri "/"
2019/11/15 10:06:04 [debug] 17660#0: *5487 uploadprogress error-tracker error: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 HTTP/1.1 200 OK
Server: openresty
Date: Fri, 15 Nov 2019 09:06:04 GMT
Content-Type: application/octet-stream
Transfer-Encoding: chunked
Connection: keep-alive

2019/11/15 10:06:04 [debug] 17660#0: *5487 write new buf t:1 f:0 000000000088A6E0, pos 000000000088A6E0, size: 167 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 http write filter: l:0 f:0 s:167
2019/11/15 10:06:04 [debug] 17660#0: *5487 http output filter "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http copy filter: "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua capture body filter, uri "/"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http postpone filter "/?" 0000000000796C90
2019/11/15 10:06:04 [debug] 17660#0: *5487 http chunk: 44
2019/11/15 10:06:04 [debug] 17660#0: *5487 write old buf t:1 f:0 000000000088A6E0, pos 000000000088A6E0, size: 167 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write new buf t:1 f:0 000000000088A870, pos 000000000088A870, size: 4 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write new buf t:1 f:0 000000000088A638, pos 000000000088A638, size: 44 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write new buf t:0 f:0 0000000000000000, pos 000000000050741D, size: 2 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 http write filter: l:0 f:0 s:217
2019/11/15 10:06:04 [debug] 17660#0: *5487 http copy filter: 0 "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua resume returned 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua light thread ended normally
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua deleting light thread
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua run thread returned 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua sending last buf of the response body
2019/11/15 10:06:04 [debug] 17660#0: *5487 http output filter "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http copy filter: "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua capture body filter, uri "/"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http postpone filter "/?" 00007FFDFCDFDA10
2019/11/15 10:06:04 [debug] 17660#0: *5487 http chunk: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write old buf t:1 f:0 000000000088A6E0, pos 000000000088A6E0, size: 167 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write old buf t:1 f:0 000000000088A870, pos 000000000088A870, size: 4 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write old buf t:1 f:0 000000000088A638, pos 000000000088A638, size: 44 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write old buf t:0 f:0 0000000000000000, pos 000000000050741D, size: 2 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 write new buf t:0 f:0 0000000000000000, pos 000000000050741A, size: 5 file: 0, size: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 http write filter: l:1 f:0 s:222
2019/11/15 10:06:04 [debug] 17660#0: *5487 http write filter limit 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 writev: 222
2019/11/15 10:06:04 [debug] 17660#0: *5487 http write filter 0000000000000000
2019/11/15 10:06:04 [debug] 17660#0: *5487 http copy filter: 0 "/?"
2019/11/15 10:06:04 [debug] 17660#0: *5487 http finalize request: 200, "/?" a:1, c:1
2019/11/15 10:06:04 [debug] 17660#0: *5487 set http keepalive handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 http close request
2019/11/15 10:06:04 [debug] 17660#0: *5487 lua request cleanup: forcible=0
2019/11/15 10:06:04 [debug] 17660#0: *5487 http log handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 run cleanup: 0000000000796B68
2019/11/15 10:06:04 [debug] 17660#0: *5487 run cleanup: 0000000000796B28
2019/11/15 10:06:04 [debug] 17660#0: *5487 free: 0000000000795CA0, unused: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 free: 000000000088A060, unused: 1440
2019/11/15 10:06:04 [debug] 17660#0: *5487 free: 0000000000915720
2019/11/15 10:06:04 [debug] 17660#0: *5487 hc free: 0000000000000000 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 hc busy: 0000000000000000 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 tcp_nodelay
2019/11/15 10:06:04 [debug] 17660#0: *5487 reusable connection: 1
2019/11/15 10:06:04 [debug] 17660#0: *5487 event timer add: 000000000091C438: 120000:1573808884074
2019/11/15 10:06:04 [debug] 17660#0: *5487 post event 0000000000988138
2019/11/15 10:06:04 [debug] 17660#0: *5487 delete posted event 0000000000988138
2019/11/15 10:06:04 [debug] 17660#0: *5487 http keepalive handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 malloc: 0000000000915720:1024
2019/11/15 10:06:04 [debug] 17660#0: *5487 recv: fd:52 -1 of 1024
2019/11/15 10:06:04 [debug] 17660#0: *5487 recv() not ready (11: Resource temporarily unavailable)
2019/11/15 10:06:04 [debug] 17660#0: *5487 free: 0000000000915720
2019/11/15 10:06:04 [debug] 17660#0: *5487 post event 0000000000988138
2019/11/15 10:06:04 [debug] 17660#0: *5487 delete posted event 0000000000988138
2019/11/15 10:06:04 [debug] 17660#0: *5487 http keepalive handler
2019/11/15 10:06:04 [debug] 17660#0: *5487 malloc: 0000000000915720:1024
2019/11/15 10:06:04 [debug] 17660#0: *5487 recv: fd:52 1024 of 1024
2019/11/15 10:06:04 [debug] 17660#0: *5487 reusable connection: 0
2019/11/15 10:06:04 [debug] 17660#0: *5487 posix_memalign: 000000000088A060:4096 @16