Opened 9 years ago

Closed 9 years ago

#815 closed defect (invalid)

Wrong timing with regards to upstream communications

Reported by: uschaufelberger@… Owned by:
Priority: minor Milestone:
Component: nginx-core Version: 1.8.x
Keywords: Cc: us@…
uname -a: Linux horst 3.16.0-46-generic #62~14.04.1-Ubuntu SMP Tue Aug 11 16:27:16 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux
nginx -V: nginx version: nginx/1.8.0
built by gcc 4.8.2 (Ubuntu 4.8.2-19ubuntu1)
built with OpenSSL 1.0.1o 12 Jun 2015
TLS SNI support enabled
configure arguments: --prefix=/opt/cargo --user=cargo --group=cargo --with-openssl=openssl-1.0.1o --with-file-aio --with-ipv6 --with-http_ssl_module --with-http_realip_module --without-mail_pop3_module --without-mail_imap_module --without-mail_smtp_module --without-http_scgi_module --without-http_uwsgi_module --error-log-path=/var/log/cargo/nginx.error.log --http-log-path=/var/log/cargo/nginx.access.log --pid-path=/var/run/nginx.pid --http-client-body-temp-path=/data/tmp/nginx/body-temp --http-proxy-temp-path=/data/tmp/nginx/proxy-temp --conf-path=/opt/cargo/etc/nginx/nginx.conf --http-fastcgi-temp-path=/data/tmp/nginx/fastcgi-temp --add-module=../nginx-upload-module --add-module=../masterzen-nginx-upload-progress-module-a788dea --add-module=../headers-more-nginx-module-0.21 --add-module=../mod_zip-01ce916943337b32d72cf0ab87f218caa8c598ab --with-debug

Description

I've been trying to figure out an issue regarding communications between nginx and our unicorn backend for a while, and I'm pretty sure I've stumbled across a bug in nginx 1.8.0

Our setup is that we're using nginx to handle large file uploads, and only pass them to our unicorn application server once the upload is finished.
However, when the upload takes longer than proxy_read_timeout (simulating this by throttling disk I/O), things will go wrong in bizarre ways:
Nginx will nicely finish the upload, pass it to upstream unicorn, and immediately throw an error regarding an upstream timeout. proxy_read_timeout is 120s in our case.
The effect can be nicely seen in the following logs, where the first timestamp comes from syslog, the second is what nginx considers the time to be. Notice how nginx (according to it's timestamps) considers the upload to be finished the second it started, which isn't really true:

daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: epoll: fd:3 ev:0005 d:00007F54EA8E3298
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http run request: "/fm/elfinder?"
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http read client request body
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 SSL_read: 7823
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http client request body recv 7823
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 add cleanup: 0000000000EE7A80
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 hashed path: /data/tmp/nginx/uploads/2/0000000002
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http script var: "ubuntu-14.04.2-server-amd64.iso"
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http script var: "application/octet-stream"
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 posix_memalign: 0000000000ED8A70:4096 @16
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http script var: "/data/tmp/nginx/uploads/2/0000000002"
daemon.info: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [info] 4313#0: *10 started uploading file "ubuntu-14.04.2-server-amd64.iso" to "/data/tmp/nginx/uploads/2/0000000002" (field "upload[]", content type "application/octet-stream"), client: 192.168.123.1, server: _, request: "POST /fm/elfinder HTTP/1.1", host: "192.168.123.123"
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 write: 12, 0000000000EE7DC0, 4096, 0
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 SSL_read: 8192
daemon.debug: Oct 14 14:41:21 horst horst nginx: 2015/10/14 14:41:21 [debug] 4313#0: *10 http client request body recv 8192

[...]

daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http client request body recv 8192
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 write: 12, 0000000000EE7DC0, 4096, 623890432
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 write: 12, 0000000000EE7DC0, 4096, 623894528
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 SSL_read: 369
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 SSL_read: 46
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http client request body recv 415
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http client request body rest 0
daemon.info: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [info] 4313#0: *10 finished uploading file "ubuntu-14.04.2-server-amd64.iso" to "/data/tmp/nginx/uploads/2/0000000002", client: 192.168.123.1, server: _, request: "POST /fm/elfinder HTTP/1.1", host: "192.168.123.123"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http script var: "623902720"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 test location: "@unicorn"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 using location: @unicorn "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 rewrite phase: 3
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 upload-progress: get_tracking_id
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 upload-progress: get_tracking_id no header found
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 upload-progress: get_tracking_id no id found
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 trackuploads no id found in POST upload req
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 rewrite phase: 4
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http script complex value
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http script var: "/opt/cargo/webapp/public"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 try files phase: 12
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 connected
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 chain writer buf fl:1 s:40
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 writev: 1372 of 1372
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 chain writer out: 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 event timer add: 12: 120000:1444826606372
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http finalize request: -4, "/fm/elfinder?" a:1, c:2
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http request count:2 blk:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http run request: "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http upstream check client, write event:1, "/fm/elfinder"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: *10 http upstream recv(): -1 (11: Resource temporarily unavailable)
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: timer delta: 5
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: worker cycle
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:41:26 [debug] 4313#0: epoll timer: 120000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: epoll: fd:3 ev:0004 d:00007F54EA8E3298
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http run request: "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream check client, write event:1, "/fm/elfinder"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream recv(): -1 (11: Resource temporarily unavailable)
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: epoll: fd:13 ev:0004 d:00007F54EA8E3371
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http run request: "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream check client, write event:1, "/heartbeat"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream recv(): -1 (11: Resource temporarily unavailable)
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: epoll: fd:14 ev:2015 d:00007F54EA8E31C1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: epoll_wait() error on fd:14 ev:2015
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream request: "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream process header
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 malloc: 0000000000EEEC40:4096
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 recv: fd:14 445 of 4096
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy status 200 "200 OK"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "Date: Wed, 14 Oct 2015 12:41:32 GMT"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "Status: 200 OK"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "Connection: close"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-Frame-Options: SAMEORIGIN"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-XSS-Protection: 1; mode=block"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-Content-Type-Options: nosniff"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "Content-Type: text/html; charset=utf-8"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-UA-Compatible: IE=Edge,chrome=1"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 posix_memalign: 0000000000EEFC50:4096 @16
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "ETag: "7215ee9c7d9dc229d2921a40e899ec5f""
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "Cache-Control: must-revalidate, private, max-age=0"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-Request-Id: 49b8e979fda1bf713ddbdc2cee7e18d3"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-Runtime: 5.921783"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header: "X-Rack-Cache: miss"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy header done
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 mod_zip: entering header filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 headers more header filter, uri "/heartbeat"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 uploadprogress error-tracker error: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 HTTP/1.1 200 OK#015#012Date: Wed, 14 Oct 2015 12:44:22 GMT#015#012Content-Type: text/html; charset=utf-8#015#012Transfer-Encoding: chunked#015#012Connection: keep-alive#015#012Vary: Accept-Encoding#015#012Status: 200 OK#015#012X-Frame-Options: SAMEORIGIN#015#012X-XSS-Protection: 1; mode=block#015#012X-Content-Type-Options: nosniff#015#012X-UA-Compatible: IE=Edge,chrome=1#015#012ETag: W/"7215ee9c7d9dc229d2921a40e899ec5f"#015#012Cache-Control: must-revalidate, private, max-age=0#015#012X-Request-Id: 49b8e979fda1bf713ddbdc2cee7e18d3#015#012Server: Zatoichi#015#012Strict-Transport-Security: max-age=16070400; includeSubdomains#015#012Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-inline' 'unsafe-eval'; img-src 'self'; style-src 'self' 'unsafe-inline'#015#012Content-Encoding: gzip#015
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write new buf t:1 f:0 0000000000EEFF70, pos 0000000000EEFF70, size: 711 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http write filter: l:0 f:0 s:711
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http cacheable: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http proxy filter init s:200 h:0 c:0 l:-1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream process upstream
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe read upstream: 1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe preread: 1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 readv: 1, last:3651
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe recv chain: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe buf free s:0 t:1 f:0 0000000000EEEC40, pos 0000000000EEEDFC, size: 1 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe length: -1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 input buf #0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe write downstream: 1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe write downstream flush in
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http output filter "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http copy filter: "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 mod_zip: entering main request body filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 mod_zip: next_body_filter due empty context or ctx->trailer_sent
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http postpone filter "/heartbeat?" 0000000000EF0338
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http gzip filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 malloc: 0000000000EFA2D0:270336
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip alloc: n:1 s:5936 a:8192 p:0000000000EFA2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip alloc: n:32768 s:2 a:65536 p:0000000000EFC2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip alloc: n:32768 s:2 a:65536 p:0000000000F0C2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip alloc: n:32768 s:2 a:65536 p:0000000000F1C2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip alloc: n:16384 s:4 a:65536 p:0000000000F2C2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in: 0000000000EF0418
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in_buf:0000000000EF0348 ni:0000000000EEEDFC ai:1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 malloc: 0000000000EF0C60:4096
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 deflate in: ni:0000000000EEEDFC no:0000000000EF0C60 ai:1 ao:4096 fl:0 redo:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 deflate out: ni:0000000000EEEDFD no:0000000000EF0C60 ai:0 ao:4096 rc:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in_buf:0000000000EF0348 pos:0000000000EEEDFC
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in: 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http copy filter: 0 "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 pipe write downstream done
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 event timer del: 14: 1444826606372
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream exit: 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 finalize http upstream request: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 finalize http proxy request
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free rr peer 1 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 close http upstream connection: 14
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000E7D0E0, unused: 48
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 reusable connection: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http upstream temp fd: -1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http output filter "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http copy filter: "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 mod_zip: entering main request body filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 mod_zip: next_body_filter due empty context or ctx->trailer_sent
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http postpone filter "/heartbeat?" 00007FFFE2421520
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http gzip filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in: 0000000000EF04D8
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in_buf:0000000000EF0488 ni:0000000000000000 ai:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 deflate in: ni:0000000000000000 no:0000000000EF0C60 ai:0 ao:4096 fl:4 redo:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 deflate out: ni:0000000000000000 no:0000000000EF0C63 ai:0 ao:4093 rc:1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 gzip in_buf:0000000000EF0488 pos:0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EFA2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http chunk: 10
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http chunk: 11
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write old buf t:1 f:0 0000000000EEFF70, pos 0000000000EEFF70, size: 711 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write new buf t:1 f:0 0000000000EF05D8, pos 0000000000EF05D8, size: 4 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write new buf t:0 f:0 0000000000000000, pos 000000000088C4E0, size: 10 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write new buf t:1 f:0 0000000000EF0C60, pos 0000000000EF0C60, size: 11 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 write new buf t:0 f:0 0000000000000000, pos 00000000005E3328, size: 7 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http write filter: l:1 f:1 s:743
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http write filter limit 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 posix_memalign: 0000000000EDB060:256 @16
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 malloc: 0000000000EFA2D0:16384
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL buf copy: 711
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL buf copy: 4
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL buf copy: 10
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL buf copy: 11
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL buf copy: 7
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL to write: 743
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 SSL_write: 743
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http write filter 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http copy filter: 0 "/heartbeat?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http finalize request: 0, "/heartbeat?" a:1, c:1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 set http keepalive handler
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http close request
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 http log handler
daemon.info: Oct 14 14:44:22 horst horst nginx: 192.168.123.1 - TLSv1.2 - ECDHE-RSA-AES256-SHA384 - - [14/Oct/2015:14:44:22 +0200] "GET /heartbeat HTTP/1.1" 200 32 175.769 175.769 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/601.1.56 (KHTML, like Gecko) Version/9.0 Safari/601.1.56" .
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: send: fd:11 289 of 289
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EF0C60
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EEEC40
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EDBF50, unused: 3
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EDCF60, unused: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EEFC50, unused: 1104
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000ED9A80
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 hc free: 0000000000000000 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 hc busy: 0000000000000000 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 free: 0000000000EFA2D0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 reusable connection: 1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *14 event timer add: 13: 30000:1444826692141
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: epoll: fd:12 ev:0004 d:00007F54EA8E3448
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream request: "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream dummy handler
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: timer delta: 175769
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 event timer del: 12: 1444826606372
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream request: "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http upstream process header
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http next upstream, 4
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free rr peer 1 4
daemon.err: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [error] 4313#0: *10 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 192.168.123.1, server: _, request: "POST /fm/elfinder HTTP/1.1", upstream: "http://unix:/var/run/cargo/unicorn.socket/fm/elfinder", host: "192.168.123.123"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 finalize http upstream request: 504
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 finalize http proxy request
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 close http upstream connection: 12
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000E60F20, unused: 48
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 reusable connection: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http finalize request: 504, "/fm/elfinder?" a:1, c:1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http special response: 504, "/fm/elfinder?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 internal redirect: "/500.html?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 rewrite phase: 1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 test location: "/"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 test location: "cargolinks"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 test location: "500.html"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 using configuration "=/500.html"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http cl:768 max:5368709120
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 rewrite phase: 3
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 rewrite phase: 4
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 post rewrite phase: 5
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 generic phase: 6
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 generic phase: 7
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 generic phase: 8
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 access phase: 9
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 access phase: 10
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 post access phase: 11
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 try files phase: 12
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 content phase: 13
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 content phase: 14
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 content phase: 15
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http filename: "/opt/cargo/webapp/public/500.html"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 add cleanup: 0000000000EEDCD8
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http static fd: 12
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 mod_zip: entering header filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 headers more header filter, uri "/500.html"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 uploadprogress error-tracker error: 504
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 uploadprogress error-tracker not tracking in this location
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 HTTP/1.1 504 Gateway Time-out#015#012Date: Wed, 14 Oct 2015 12:44:22 GMT#015#012Content-Type: text/html#015#012Content-Length: 2089#015#012Connection: keep-alive#015#012ETag: "561c2255-829"#015#012Server: Zatoichi#015
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 write new buf t:1 f:0 0000000000EEDEB8, pos 0000000000EEDEB8, size: 181 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http write filter: l:0 f:0 s:181
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http output filter "/500.html?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http copy filter: "/500.html?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 read: 12, 0000000000EEE040, 2089, 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 mod_zip: entering main request body filter
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 mod_zip: next_body_filter due empty context or ctx->trailer_sent
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http postpone filter "/500.html?" 0000000000EEDA48
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 write old buf t:1 f:0 0000000000EEDEB8, pos 0000000000EEDEB8, size: 181 file: 0, size: 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 write new buf t:1 f:1 0000000000EEE040, pos 0000000000EEE040, size: 2089 file: 0, size: 2089
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http write filter: l:1 f:0 s:2270
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http write filter limit 0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 malloc: 0000000000EFA2D0:16384
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 SSL buf copy: 181
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 SSL buf copy: 2089
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 SSL to write: 2270
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 SSL_write: 2270
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http write filter 0000000000000000
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http copy filter: 0 "/500.html?"
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http finalize request: 0, "/500.html?" a:1, c:2
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http request count:2 blk:0
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http finalize request: -4, "/500.html?" a:1, c:1
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 set http keepalive handler
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http close request
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 http log handler
daemon.info: Oct 14 14:44:22 horst horst nginx: 192.168.123.1 - TLSv1.2 - ECDHE-RSA-AES256-SHA384 - - [14/Oct/2015:14:44:22 +0200] "POST /fm/elfinder HTTP/1.1" 504 2089 180.667 175.769 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_5) AppleWebKit/601.1.56 (KHTML, like Gecko) Version/9.0 Safari/601.1.56" .
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: send: fd:11 294 of 294
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 run cleanup: 0000000000EEDCD8
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 file cleanup: fd:12
daemon.debug: Oct 14 14:44:22 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 run cleanup: 0000000000EE7A80

[Our application chokes because it cannot find the referenced file, and returns an error 504]

daemon.info: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [info] 4313#0: *10 finished cleanup of file "/data/tmp/nginx/uploads/2/0000000002" after http status 504 while closing request, client: 192.168.123.1, server: 192.168.123.123:443
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EE8DD0
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EE7DC0
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000E6E970, unused: 1
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EE6DB0, unused: 0
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000ED8A70, unused: 0
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EECC20, unused: 2
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EEDC30, unused: 596
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 free: 0000000000EEB430
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 hc free: 0000000000000000 0
daemon.debug: Oct 14 14:44:55 horst horst nginx: 2015/10/14 14:44:22 [debug] 4313#0: *10 hc busy: 0000000000000000 0

If there's any additional information (e.g. nginx config or further debug output) you need in order to verify this, just let me know

Cheers

Urs

Change History (1)

comment:1 by Maxim Dounin, 9 years ago

Resolution: invalid
Status: newclosed

The description suggests you are having problems with a 3rd party module. This is a wrong place to report 3rd party module problems, this trac is to track bugs in nginx itself.

Note: See TracTickets for help on using tickets.