Opened 9 years ago
Closed 9 years ago
#815 closed defect (invalid)
Wrong timing with regards to upstream communications
Reported by: | 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
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.