# Nginx worker stuck, potential mod\_zip bug **URL:** \ **Category:** NGINX\ **Created:** [February 18, 2012, 1:04am UTC](https://www.ruby-forum.com/t/nginx-worker-stuck-potential-mod-zip-bug/216974 "2012-02-18T01:04:27Z")\ **Posts on this page:** 2\ **Page:** 1
**Author:** ![luislavena](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/l/0ea827/32.png) [@luislavena](https://www.ruby-forum.com/u/luislavena)\ **Post date:** [February 18, 2012, 1:04am UTC](https://www.ruby-forum.com/t/nginx-worker-stuck-potential-mod-zip-bug/216974/1 "2012-02-18T01:04:27Z")
I’m running an older version of nginx (0.7.67) with mod\_zip 1.1.6. I believe we have a found a rare bug, I’m trying to figure out of it is with mod\_zip or with nginx, and if upgrading nginx will potentially resolve it. The symptom is a worker process getting “stuck” at 100% CPU, leaving all connections in CLOSE\_WAIT, and servicing no requests. It appears that the trigger for this is downloading an archive from mod\_zip, but we have never been able to reproduce it, only observe it in production. I was finally able to catch one of the workers and get a backtrace from gdb: $ cat backtrace.log | addr2line -e /usr/lib/debug/usr/sbin/nginx -f ngx\_http\_postpone\_filter /build/buildd/nginx-0.7.67/src/http/ngx\_http\_postpone\_filter\_module.c:125 ngx\_http\_ssi\_body\_filter /build/buildd/nginx-0.7.67/src/http/modules/ngx\_http\_ssi\_filter\_module.c:430 ngx\_http\_charset\_body\_filter /build/buildd/nginx-0.7.67/src/http/modules/ngx\_http\_charset\_filter\_module.c:643 ngx\_http\_zip\_body\_filter /build/buildd/nginx-0.7.67/modules/mod\_zip-1.1.6/ngx\_http\_zip\_module.c:336 ngx\_output\_chain /build/buildd/nginx-0.7.67/src/core/ngx\_output\_chain.c:58 ngx\_http\_copy\_filter /build/buildd/nginx-0.7.67/src/http/ngx\_http\_copy\_filter\_module.c:114 ngx\_http\_range\_body\_filter /build/buildd/nginx-0.7.67/src/http/modules/ngx\_http\_range\_filter\_module.c:549 ngx\_http\_output\_filter /build/buildd/nginx-0.7.67/src/http/ngx\_http\_core\_module.c:1716 ngx\_event\_pipe\_write\_to\_downstream /build/buildd/nginx-0.7.67/src/event/ngx\_event\_pipe.c:627 ngx\_http\_upstream\_process\_upstream /build/buildd/nginx-0.7.67/src/http/ngx\_http\_upstream.c:2509 ngx\_http\_upstream\_handler /build/buildd/nginx-0.7.67/src/http/ngx\_http\_upstream.c:844 ngx\_event\_process\_posted /build/buildd/nginx-0.7.67/src/event/ngx\_event\_posted.c:30 ngx\_worker\_process\_cycle /build/buildd/nginx-0.7.67/src/os/unix/ngx\_process\_cycle.c:793 ngx\_spawn\_process /build/buildd/nginx-0.7.67/src/os/unix/ngx\_process.c:201 ngx\_reap\_children /build/buildd/nginx-0.7.67/src/os/unix/ngx\_process\_cycle.c:612 main /build/buildd/nginx-0.7.67/src/core/nginx.c:396 ?? ??:0 \_start ??:0 ?? ??:0 ?? ??:0 ?? ??:0 ?? ??:0 ?? ??:0 ?? ??:0 I also had the log in debug mode (it is incredibly large ~ 150GB uncompressed) and it is completely filled with the following little loop: 2012/02/17 11:58:45 [debug] 10150#0: \*1888 mod\_zip: entering subrequest body filter 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http postpone filter “/s3/bucket/key” 0000000000000000 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: 0 “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write busy: 8192 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write: out:0000000000000000, f:1 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http output filter “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 mod\_zip: entering subrequest body filter 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http postpone filter “/s3/bucket/key” 0000000000000000 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: 0 “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write busy: 8192 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write: out:0000000000000000, f:1 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http output filter “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 mod\_zip: entering subrequest body filter 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http postpone filter “/s3/bucket/key” 0000000000000000 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: 0 “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write busy: 8192 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write: out:0000000000000000, f:1 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http output filter “/s3/bucket/key” 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: “/s3/bucket/key” Am I right in assuming this is a bug in mod\_zip, it looks like a buffer is never being drained to the client? ---
**Author:** ![WSandrew\_L](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/w/d07c76/32.png) [@WSandrew\_L](https://www.ruby-forum.com/u/WSandrew_L)\ **Post date:** [February 18, 2012, 11:11pm UTC](https://www.ruby-forum.com/t/nginx-worker-stuck-potential-mod-zip-bug/216974/2 "2012-02-18T23:11:23Z")
Hello! On Fri, Feb 17, 2012 at 04:03:46PM -0800, W. Andrew Loe III wrote: > I’m running an older version of nginx (0.7.67) with mod\_zip 1.1.6. I > believe we have a found a rare bug, I’m trying to figure out of it is > with mod\_zip or with nginx, and if upgrading nginx will potentially > resolve it. > > The symptom is a worker process getting “stuck” at 100% CPU, leaving > all connections in CLOSE\_WAIT, and servicing no requests. It appears > that the trigger for this is downloading an archive from mod\_zip, but > we have never been able to reproduce it, only observe it in > production. […] > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write busy: 8192 > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 pipe write: out:0000000000000000, f:1 > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http output filter “/s3/bucket/key” > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 copy filter: “/s3/bucket/key” > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 mod\_zip: entering > subrequest body filter > 2012/02/17 11:58:45 [debug] 10150#0: \*1888 http postpone filter > “/s3/bucket/key” 0000000000000000 […] > Am I right in assuming this is a bug in mod\_zip, it looks like a > buffer is never being drained to the client? Quick look though mod\_zip sources suggests it doesn’t do anything for this request (subrequest). I would rather think you’ve hit something like this problem: [http://trac.nginx.org/nginx/changeset/4136/nginx](http://trac.nginx.org/nginx/changeset/4136/nginx) Try upgrading to 1.1.4+/1.0.7+ to see if it helps. Maxim D.