Can't get a simple proxy to cache anything
Phil Endecott
nginx_list at chezphil.org
Fri Jan 22 16:47:07 UTC 2021
Dear Experts,
I am trying to set up a simple limited caching proxy; I have got
proxying to work, but I can't get it to cache.
I'm a software developer, working from my home office. I have a fast
home network, a slow connection to the internet, and fast cloud servers
(e.g. AWS). I'd like to be able to cache content from some specific
domains locally, to make it faster. This is simple http static content
- no ssl, no auth, no cookies.
I've installed Debian packages of nginx 1.14.2 in a home server with
a large disk. The nginx configuration is as follows:
user www-data;
worker_processes auto;
pid /run/nginx.pid;
events {
worker_connections 768;
}
http {
sendfile on;
tcp_nopush on;
tcp_nodelay on;
keepalive_timeout 65;
types_hash_max_size 2048;
include /etc/nginx/mime.types;
default_type application/octet-stream;
ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
ssl_prefer_server_ciphers on;
access_log /var/log/nginx/access.log;
error_log /var/log/nginx/error.log debug;
gzip on;
proxy_cache_path /var/cache/nginx/proxy_cache use_temp_path=off inactive=10y levels=1:2 keys_zone=cachekeys:10M max_size=2G;
server {
listen 82 default_server;
listen [::]:82 default_server;
resolver 192.168.1.43; # A local box running dnsmasq as a DNS forwarder.
proxy_cache cachekeys;
proxy_cache_convert_head off;
proxy_cache_key "$request_method$scheme$host$request_uri";
proxy_cache_revalidate on;
proxy_http_version 1.1;
proxy_redirect off;
proxy_buffering on;
location / {
proxy_pass http://$host;
}
}
}
Here's what happens when I fetch a test file un-proxied:
$ wget -S http://XXXX.org/index.html
--2021-01-22 16:28:34-- http://XXXX.org/index.html
Resolving XXXX.org (XXXX.org)... 34.255.xx.yy
Connecting to XXXX.org (XXXX.org)|34.255.xx.yy|:80... connected.
HTTP request sent, awaiting response...
HTTP/1.1 200 OK
Date: Fri, 22 Jan 2021 16:28:34 GMT
Server: Apache
Last-Modified: Sun, 14 Jun 2020 14:53:25 GMT
Accept-Ranges: bytes
Content-Length: 9174
Vary: Accept-Encoding
ETag: "23d6-5a80c78e6ed8d-gzip"
X-Frame-Options: sameorigin
Keep-Alive: timeout=30
Connection: Keep-Alive
Content-Type: text/html
Length: 9174 (9.0K) [text/html]
Saving to: ‘index.html.4’
index.html.4 100%[===================>] 8.96K --.-KB/s in 0.005s
2021-01-22 16:28:34 (1.78 MB/s) - ‘index.html.4’ saved [9174/9174]
Now I try to fetch using the proxy (hostname PPPP):
$ export http_proxy=http://PPPP:82
$ wget -S http://XXXX.org/index.html
--2021-01-22 16:31:16-- http://XXXX.org/index.html
Resolving PPPP (PPPP)... fd31:4159:2600:0:21e:6ff:fe36:ec9d, 192.168.1.50
Connecting to PPPP (PPPP)|fd31:4159:2600:0:21e:6ff:fe36:ec9d|:82... connected.
Proxy request sent, awaiting response...
HTTP/1.1 200 OK
Server: nginx/1.14.2
Date: Fri, 22 Jan 2021 16:31:16 GMT
Content-Type: text/html
Content-Length: 9174
Connection: keep-alive
Last-Modified: Sun, 14 Jun 2020 14:53:25 GMT
Vary: Accept-Encoding
ETag: "23d6-5a80c78e6ed8d-gzip"
X-Frame-Options: sameorigin
Accept-Ranges: bytes
Length: 9174 (9.0K) [text/html]
Saving to: ‘index.html.7’
index.html.7 100%[====================================================>] 8.96K --.-KB/s in 0.005s
2021-01-22 16:31:16 (1.75 MB/s) - ‘index.html.7’ saved [9174/9174]
So the proxy has successfully retrieved the file - but it has not been cached;
there is nothing saved in /var/cache/nginx.
Looking in the nginx debug log, I see this:
2021/01/22 16:25:38 [debug] 18695#18695: *18 http cacheable: 0
So my guess is that something about the http request or response, or
in the nginx configuration, has caused nginx to decide that this response
is not cacheable.
Can anyone see what the problem is?
A longer extract from the debug log follows.
Thanks,
Phil.
2021/01/22 16:25:37 [debug] 18695#18695: accept on [::]:82, ready: 0
2021/01/22 16:25:37 [debug] 18695#18695: posix_memalign: 00563640:256 @16
2021/01/22 16:25:37 [debug] 18695#18695: *18 accept: [fd31:4159:2600:0:21e:6ff:fe33:322b]:39882 fd:4
2021/01/22 16:25:37 [debug] 18695#18695: *18 event timer add: 4: 60000:1061794893
2021/01/22 16:25:37 [debug] 18695#18695: *18 reusable connection: 1
2021/01/22 16:25:37 [debug] 18695#18695: *18 epoll add event: fd:4 op:1 ev:80002001
2021/01/22 16:25:37 [debug] 18695#18695: *18 http wait request handler
2021/01/22 16:25:37 [debug] 18695#18695: *18 posix_memalign: 00563770:256 @16
2021/01/22 16:25:37 [debug] 18695#18695: *18 malloc: 00563888:1024
2021/01/22 16:25:37 [debug] 18695#18695: *18 recv: eof:0, avail:1
2021/01/22 16:25:37 [debug] 18695#18695: *18 recv: fd:4 196 of 1024
2021/01/22 16:25:37 [debug] 18695#18695: *18 reusable connection: 0
2021/01/22 16:25:37 [debug] 18695#18695: *18 posix_memalign: 0056CB80:4096 @16
2021/01/22 16:25:37 [debug] 18695#18695: *18 http process request line
2021/01/22 16:25:37 [debug] 18695#18695: *18 http request line: "GET http://XXXX.org/index.html HTTP/1.1"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http uri: "/index.html"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http args: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http exten: "html"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http process request header line
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "User-Agent: Wget/1.18 (linux-gnu)"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "Accept: */*"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "Accept-Encoding: identity"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "Host: XXXX.org"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "Connection: Keep-Alive"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header: "Proxy-Connection: Keep-Alive"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http header done
2021/01/22 16:25:37 [debug] 18695#18695: *18 event timer del: 4: 1061794893
2021/01/22 16:25:37 [debug] 18695#18695: *18 generic phase: 0
2021/01/22 16:25:37 [debug] 18695#18695: *18 rewrite phase: 1
2021/01/22 16:25:37 [debug] 18695#18695: *18 test location: "/"
2021/01/22 16:25:37 [debug] 18695#18695: *18 using configuration "/"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http cl:-1 max:1048576
2021/01/22 16:25:37 [debug] 18695#18695: *18 rewrite phase: 3
2021/01/22 16:25:37 [debug] 18695#18695: *18 post rewrite phase: 4
2021/01/22 16:25:37 [debug] 18695#18695: *18 generic phase: 5
2021/01/22 16:25:37 [debug] 18695#18695: *18 access phase: 6
2021/01/22 16:25:37 [debug] 18695#18695: *18 access phase: 7
2021/01/22 16:25:37 [debug] 18695#18695: *18 access phase: 8
2021/01/22 16:25:37 [debug] 18695#18695: *18 post access phase: 9
2021/01/22 16:25:37 [debug] 18695#18695: *18 generic phase: 10
2021/01/22 16:25:37 [debug] 18695#18695: *18 generic phase: 11
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: "http://"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "XXXX.org"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http init upstream, client timer: 0
2021/01/22 16:25:37 [debug] 18695#18695: *18 epoll add event: fd:4 op:3 ev:80002005
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "GET"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "http"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "XXXX.org"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "/index.html"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http cache key: "GEThttpXXXX.org/index.html"
2021/01/22 16:25:37 [debug] 18695#18695: *18 add cleanup: 0056DA80
2021/01/22 16:25:37 [debug] 18695#18695: *18 http file cache exists: -5 e:0
2021/01/22 16:25:37 [debug] 18695#18695: *18 cache file: "/var/cache/nginx/proxy_cache/9/2d304c870502df72ddc8aad3e08ab229"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http upstream cache: -5
2021/01/22 16:25:37 [debug] 18695#18695: *18 posix_memalign: 0059F040:4096 @16
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: "Host"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script var: "XXXX.org"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: "Connection"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: "close"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http script copy: ""
2021/01/22 16:25:37 [debug] 18695#18695: *18 http proxy header: "User-Agent: Wget/1.18 (linux-gnu)"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http proxy header: "Accept: */*"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http proxy header: "Accept-Encoding: identity"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http proxy header: "Proxy-Connection: Keep-Alive"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http proxy header:
"GET /index.html HTTP/1.1
Host: XXXX.org
Connection: close
User-Agent: Wget/1.18 (linux-gnu)
Accept: */*
Accept-Encoding: identity
Proxy-Connection: Keep-Alive
"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http cleanup add: 0056DB70
2021/01/22 16:25:37 [debug] 18695#18695: *18 http finalize request: -4, "/index.html?" a:1, c:2
2021/01/22 16:25:37 [debug] 18695#18695: *18 http request count:2 blk:0
2021/01/22 16:25:37 [debug] 18695#18695: *18 http run request: "/index.html?"
2021/01/22 16:25:37 [debug] 18695#18695: *18 http upstream check client, write event:1, "/index.html"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream resolve: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 name was resolved to 34.255.xx.yy
2021/01/22 16:25:38 [debug] 18695#18695: *18 get rr peer, try: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 stream socket 22
2021/01/22 16:25:38 [debug] 18695#18695: *18 epoll add connection: fd:22 ev:80002005
2021/01/22 16:25:38 [debug] 18695#18695: *18 connect to 34.255.xx.yy:80, fd:22 #19
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream connect: -2
2021/01/22 16:25:38 [debug] 18695#18695: *18 posix_memalign: 005634C0:128 @16
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer add: 22: 60000:1061795045
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream send request handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream send request
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream send request body
2021/01/22 16:25:38 [debug] 18695#18695: *18 chain writer buf fl:1 s:172
2021/01/22 16:25:38 [debug] 18695#18695: *18 chain writer in: 0059F240
2021/01/22 16:25:38 [debug] 18695#18695: *18 writev: 172 of 172
2021/01/22 16:25:38 [debug] 18695#18695: *18 chain writer out: 00000000
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer del: 22: 1061795045
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer add: 22: 60000:1061795073
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream process header
2021/01/22 16:25:38 [debug] 18695#18695: *18 malloc: 005A0048:4096
2021/01/22 16:25:38 [debug] 18695#18695: *18 recv: eof:0, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 recv: fd:22 1448 of 3751
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy status 200 "200 OK"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Date: Fri, 22 Jan 2021 16:25:38 GMT"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Server: Apache"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Last-Modified: Sun, 14 Jun 2020 14:53:25 GMT"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Accept-Ranges: bytes"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Content-Length: 9174"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Vary: Accept-Encoding"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "ETag: "23d6-5a80c78e6ed8d-gzip""
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "X-Frame-Options: sameorigin"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Connection: close"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header: "Content-Type: text/html"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy header done
2021/01/22 16:25:38 [debug] 18695#18695: *18 HTTP/1.1 200 OK
Server: nginx/1.14.2
Date: Fri, 22 Jan 2021 16:25:38 GMT
Content-Type: text/html
Content-Length: 9174
Connection: keep-alive
Last-Modified: Sun, 14 Jun 2020 14:53:25 GMT
Vary: Accept-Encoding
ETag: "23d6-5a80c78e6ed8d-gzip"
X-Frame-Options: sameorigin
Accept-Ranges: bytes
2021/01/22 16:25:38 [debug] 18695#18695: *18 write new buf t:1 f:0 0059F5E0, pos 0059F5E0, size: 302 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter: l:0 f:0 s:302
2021/01/22 16:25:38 [debug] 18695#18695: *18 http cacheable: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http file cache free, fd: -1
2021/01/22 16:25:38 [debug] 18695#18695: *18 http proxy filter init s:200 h:0 c:0 l:9174
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream process upstream
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe preread: 1157
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A02C4, size: 1157 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 9174
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write busy: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write: out:00000000, f:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A02C4, size: 1157 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 9174
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer: 22, old: 1061795073, new: 1061795105
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream dummy handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream process upstream
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: eof:0, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: 1, last:2303
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe recv chain: 2303
2021/01/22 16:25:38 [debug] 18695#18695: *18 input buf #0
2021/01/22 16:25:38 [debug] 18695#18695: *18 malloc: 005A1050:4096
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: eof:0, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: 1, last:4096
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe recv chain: 593
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf in s:1 t:1 f:0 005A0048, pos 005A02C4, size: 3460 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A1050, pos 005A1050, size: 593 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write busy: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write buf ls:1 005A02C4 3460
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write: out:0059F7F0, f:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http output filter "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http postpone filter "/index.html?" 0059F7F0
2021/01/22 16:25:38 [debug] 18695#18695: *18 write old buf t:1 f:0 0059F5E0, pos 0059F5E0, size: 302 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 write new buf t:1 f:0 005A0048, pos 005A02C4, size: 3460 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter: l:0 f:1 s:3762
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter limit 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 writev: 3762 of 3762
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter 00000000
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: 0 "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write busy: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write: out:00000000, f:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A1050, pos 005A1050, size: 593 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A0048, size: 0 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer: 22, old: 1061795073, new: 1061795105
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream dummy handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream process upstream
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: eof:0, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: 2, last:4096
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe recv chain: 2896
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A1050, pos 005A1050, size: 3489 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A0048, size: 0 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write busy: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write: out:00000000, f:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A1050, pos 005A1050, size: 3489 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A0048, size: 0 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer: 22, old: 1061795073, new: 1061795109
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream dummy handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream request: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream process upstream
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe read upstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: eof:1, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: 2, last:4096
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe recv chain: 2225
2021/01/22 16:25:38 [debug] 18695#18695: *18 input buf #1
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: eof:1, avail:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 readv: 1, last:2478
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe recv chain: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf in s:1 t:1 f:0 005A1050, pos 005A1050, size: 4096 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe buf free s:0 t:1 f:0 005A0048, pos 005A0048, size: 1618 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe length: 1618
2021/01/22 16:25:38 [debug] 18695#18695: *18 input buf #2
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream flush in
2021/01/22 16:25:38 [debug] 18695#18695: *18 http output filter "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http postpone filter "/index.html?" 0059F8E0
2021/01/22 16:25:38 [debug] 18695#18695: *18 write new buf t:1 f:0 005A1050, pos 005A1050, size: 4096 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 write new buf t:1 f:0 005A0048, pos 005A0048, size: 1618 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter: l:0 f:0 s:5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter limit 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 writev: 5714 of 5714
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter 00000000
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: 0 "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 pipe write downstream done
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer: 22, old: 1061795073, new: 1061795113
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream exit: 00000000
2021/01/22 16:25:38 [debug] 18695#18695: *18 finalize http upstream request: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 finalize http proxy request
2021/01/22 16:25:38 [debug] 18695#18695: *18 free rr peer 1 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 close http upstream connection: 22
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 005634C0, unused: 88
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer del: 22: 1061795073
2021/01/22 16:25:38 [debug] 18695#18695: *18 reusable connection: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http upstream temp fd: -1
2021/01/22 16:25:38 [debug] 18695#18695: *18 http output filter "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http postpone filter "/index.html?" BE8617F4
2021/01/22 16:25:38 [debug] 18695#18695: *18 write new buf t:0 f:0 00000000, pos 00000000, size: 0 file: 0, size: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http write filter: l:1 f:0 s:0
2021/01/22 16:25:38 [debug] 18695#18695: *18 http copy filter: 0 "/index.html?"
2021/01/22 16:25:38 [debug] 18695#18695: *18 http finalize request: 0, "/index.html?" a:1, c:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 set http keepalive handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 http close request
2021/01/22 16:25:38 [debug] 18695#18695: *18 http log handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 run cleanup: 0056DA80
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 005A1050
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 005A0048
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 0056CB80, unused: 4
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 0059F040, unused: 1545
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 00563888
2021/01/22 16:25:38 [debug] 18695#18695: *18 hc free: 00000000
2021/01/22 16:25:38 [debug] 18695#18695: *18 hc busy: 00000000 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 tcp_nodelay
2021/01/22 16:25:38 [debug] 18695#18695: *18 reusable connection: 1
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer add: 4: 65000:1061800113
2021/01/22 16:25:38 [debug] 18695#18695: *18 http keepalive handler
2021/01/22 16:25:38 [debug] 18695#18695: *18 malloc: 00563888:1024
2021/01/22 16:25:38 [debug] 18695#18695: *18 recv: eof:1, avail:1
2021/01/22 16:25:38 [debug] 18695#18695: *18 recv: fd:4 0 of 1024
2021/01/22 16:25:38 [info] 18695#18695: *18 client fd31:4159:2600:0:21e:6ff:fe33:322b closed keepalive connection
2021/01/22 16:25:38 [debug] 18695#18695: *18 close http connection: 4
2021/01/22 16:25:38 [debug] 18695#18695: *18 event timer del: 4: 1061800113
2021/01/22 16:25:38 [debug] 18695#18695: *18 reusable connection: 0
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 00563888
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 00563640, unused: 24
2021/01/22 16:25:38 [debug] 18695#18695: *18 free: 00563770, unused: 184
More information about the nginx
mailing list