# After reload, nginx's CPU usage jumped to 100 percent（backtrace provided)

**URL:** <https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358>\
**Category:** NGINX\
**Created:** [July 12, 2011, 3:31pm UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358 "2011-07-12T15:31:56Z")\
**Posts on this page:** 5\
**Page:** 1

<div class="post-metadata">

**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:** [July 12, 2011, 3:31pm UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358/1 "2011-07-12T15:31:56Z")

</div>

After reload, all the worker processes, including newly forked ones,  
goes  
straight to 100% CPU:

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND

17301 nobody 25 0 2670m 107m 1128 R 99.6 0.7 2:00.87 nginx

17306 nobody 25 0 2651m 86m 444 R 98.6 0.5 2:00.82 nginx  
(cache  
manager)

17303 nobody 25 0 2670m 106m 788 R 49.8 0.7 1:01.31 nginx

17302 nobody 25 0 2670m 106m 792 R 47.8 0.7 0:59.96 nginx

17305 nobody 25 0 2670m 106m 652 R 47.8 0.7 1:01.08 nginx  
17304 nobody 25 0 2670m 106m 652 R 100.6 0.7 2:01.23 nginx

15759 nobody 25 0 2670m 197m 91m R 45.8 1.2 2:37.60 nginx  
15761 nobody 25 0 2651m 172m 86m R 54.8 1.1 1:01.59 nginx  
(cache  
manager)  
15760 nobody 25 0 2670m 197m 91m R 51.8 1.2 2:43.36 nginx  
15756 nobody 25 0 2670m 197m 91m R 99.6 1.2 3:41.27 nginx

15757 nobody 25 0 2670m 197m 91m R 49.8 1.2 2:37.74 nginx

15758 nobody 25 0 2670m 197m 91m R 49.8 1.2 2:37.31 nginx

Using GDB, it seems worker processes stuck at this point:

## (gdb) bt #0 0x00000033ad4badd7 in sched\_yield () from /lib64/libc.so.6 #1 0x000000000040e849 in ngx\_shmtx\_lock (mtx=0x2b3410964048) at src/core/ngx\_shmtx.c:136 #2 0x0000000000444712 in ngx\_http\_file\_cache\_update (r=0xe50f3b0, tf=0x9e60270) at src/http/ngx\_http\_file\_cache.c:831 #3 0x000000000043af8e in ngx\_http\_upstream\_process\_request (r=0xe50f3b0) at src/http/ngx\_http\_upstream.c:2657 #4 0x000000000043b08e in ngx\_http\_upstream\_process\_upstream (r=0xe50f3b0, u=0x9e5f1f8) at src/http/ngx\_http\_upstream.c:2599 #5 0x000000000043b192 in ngx\_http\_upstream\_handler (ev=) at src/http/ngx\_http\_upstream.c:903 #6 0x0000000000418eaa in ngx\_event\_process\_posted (cycle=, posted=0x7fff3f606520) at src/event/ngx\_event\_posted.c:39 #7 0x0000000000418d6f in ngx\_process\_events\_and\_timers (cycle=0xd2a7710) at src/event/ngx\_event.c:272 #8 0x000000000041e800 in ngx\_worker\_process\_cycle (cycle=0xd2a7710, data=) at src/os/unix/ngx\_process\_cycle.c:800 #9 0x000000000041d137 in ngx\_spawn\_process (cycle=0xd2a7710, proc=0x41e738 \<ngx\_worker\_process\_cycle\>, data=0x0, name=0x5652a1 “worker process”, respawn=-4) at src/os/unix/ngx\_process.c:196 #10 0x000000000041dea3 in ngx\_start\_worker\_processes (cycle=0xd2a7710, n=5, type=-4) at src/os/unix/ngx\_process\_cycle.c:360 #11 0x000000000041f351 in ngx\_master\_process\_cycle (cycle=0xd2a7710) at src/os/unix/ngx\_process\_cycle.c:249 #12 0x0000000000404dda in main (argc=7, argv=0x972556d) at src/core/nginx.c:405

Attaching to process 17301  
(gdb) bt  
#0 0x00000033ad4badd7 in sched\_yield () from /lib64/libc.so.6  
#1 0x000000000040e849 in ngx\_shmtx\_lock (mtx=0x2b3410964048) at  
src/core/ngx\_shmtx.c:136  
#2 0x00000000004442ce in ngx\_http\_file\_cache\_free (c=0xc036b50, tf=0x0)  
at  
src/http/ngx\_http\_file\_cache.c:916  
#3 0x0000000000444473 in ngx\_http\_file\_cache\_cleanup (data=) at src/http/ngx\_http\_file\_cache.c:978  
#4 0x0000000000405924 in ngx\_destroy\_pool (pool=0xc035ac0) at  
src/core/ngx\_palloc.c:54  
#5 0x000000000042c0da in ngx\_http\_free\_request (r=0xaee17b0, rc=0) at  
src/http/ngx\_http\_request.c:2996  
#6 0x000000000042dd6d in ngx\_http\_set\_keepalive (r=0xaee17b0) at  
src/http/ngx\_http\_request.c:2450  
#7 ngx\_http\_finalize\_connection (r=0xaee17b0) at  
src/http/ngx\_http\_request.c:2146  
#8 0x000000000042e2d9 in ngx\_http\_finalize\_request (r=0x2b3410964048,  
rc=0)  
at src/http/ngx\_http\_request.c:1879  
#9 0x000000000042a5dc in ngx\_http\_core\_content\_phase (r=0xaee17b0,  
ph=0xeb273b0) at src/http/ngx\_http\_core\_module.c:1339  
#10 0x0000000000425d03 in ngx\_http\_core\_run\_phases (r=0xaee17b0) at  
src/http/ngx\_http\_core\_module.c:837  
#11 0x0000000000425e00 in ngx\_http\_handler (r=0x2b3410964048) at  
src/http/ngx\_http\_core\_module.c:820  
#12 0x000000000042ebfd in ngx\_http\_process\_request (r=0xaee17b0) at  
src/http/ngx\_http\_request.c:1650  
#13 0x000000000042f420 in ngx\_http\_process\_request\_headers (rev=) at src/http/ngx\_http\_request.c:1093  
#14 0x000000000042f922 in ngx\_http\_process\_request\_line  
(rev=0x2b33ce0c4690)  
at src/http/ngx\_http\_request.c:893  
#15 0x000000000042cefe in ngx\_http\_init\_request (rev=0x2b33ce0c4690) at  
src/http/ngx\_http\_request.c:518  
#16 0x0000000000418eaa in ngx\_event\_process\_posted (cycle=, posted=0x0) at src/event/ngx\_event\_posted.c:39  
#17 0x0000000000418d6f in ngx\_process\_events\_and\_timers  
(cycle=0x9b4da50) at  
src/event/ngx\_event.c:272  
#18 0x000000000041e800 in ngx\_worker\_process\_cycle (cycle=0x9b4da50,  
data=)  
at src/os/unix/ngx\_process\_cycle.c:800  
#19 0x000000000041d137 in ngx\_spawn\_process (cycle=0x9b4da50,  
proc=0x41e738  
\<ngx\_worker\_process\_cycle\>, data=0x0,  
name=0x5652a1 “worker process”, respawn=-4) at  
src/os/unix/ngx\_process.c:196  
#20 0x000000000041dea3 in ngx\_start\_worker\_processes (cycle=0x9b4da50,  
n=5,  
type=-4) at src/os/unix/ngx\_process\_cycle.c:360  
#21 0x000000000041f351 in ngx\_master\_process\_cycle (cycle=0x9b4da50) at  
src/os/unix/ngx\_process\_cycle.c:249  
#22 0x0000000000404dda in main (argc=7, argv=0x972556d) at  
src/core/nginx.c:405

Also, we took backtrace for cache manger process:

Attaching to process 17306  
ngx\_http\_file\_cache\_expire (data=) at  
src/http/ngx\_http\_file\_cache.c:1096  
1096 if (fcn-\>count == 0) {  
(gdb) bt  
#0 ngx\_http\_file\_cache\_expire (data=) at  
src/http/ngx\_http\_file\_cache.c:1096  
#1 ngx\_http\_file\_cache\_manager (data=) at  
src/http/ngx\_http\_file\_cache.c:1191  
#2 0x000000000041e92a in ngx\_cache\_manager\_process\_handler  
(ev=0x7fff3f606670) at src/os/unix/ngx\_process\_cycle.c:1346  
#3 0x0000000000418e15 in ngx\_event\_expire\_timers () at  
src/event/ngx\_event\_timer.c:149  
#4 0x0000000000418d44 in ngx\_process\_events\_and\_timers  
(cycle=0x9b4da50) at  
src/event/ngx\_event.c:261  
#5 0x000000000041f5f8 in ngx\_cache\_manager\_process\_cycle  
(cycle=0x9b4da50,  
data=)  
at src/os/unix/ngx\_process\_cycle.c:1328  
#6 0x000000000041d137 in ngx\_spawn\_process (cycle=0x9b4da50,  
proc=0x41f489  
\<ngx\_cache\_manager\_process\_cycle\>, data=0x7e9040,  
name=0x56525f “cache manager process”, respawn=-4) at  
src/os/unix/ngx\_process.c:196  
#7 0x000000000041dd8a in ngx\_start\_cache\_manager\_processes  
(cycle=0x9b4da50, respawn=1) at src/os/unix/ngx\_process\_cycle.c:398  
#8 0x000000000041f35e in ngx\_master\_process\_cycle (cycle=0x9b4da50) at  
src/os/unix/ngx\_process\_cycle.c:251  
#9 0x0000000000404dda in main (argc=7, argv=0x972556d) at  
src/core/nginx.c:405

The nginx version is 1.0.4 with following configuration parameters:

nginx: nginx version: nginx/1.0.4  
nginx: built by gcc 4.1.2 20080704 (Red Hat 4.1.2-50)  
nginx: TLS SNI support enabled  
nginx: configure arguments: --prefix=/opt/app/nginx-urlhash  
–without-select\_module --without-poll\_module --with-http\_ssl\_module  
–with-http\_realip\_module --with-http\_addition\_module  
–with-http\_sub\_module  
–with-http\_flv\_module --with-http\_gzip\_static\_module  
–with-http\_stub\_status\_module --with-pcre=/opt/tmp/pcre-8.10  
–with-openssl=/opt/tmp/openssl-1.0.0a  
–add-module=/opt/tmp/substitutions4nginx  
–add-module=/opt/tmp/ngx\_cache\_purge-1.3

---

<div class="post-metadata">

**Author:** ![SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/91b2a8/32.png) [@SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/u/SSSSSSS_SS_SSS)\
**Post date:** [July 12, 2011, 4:09pm UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358/2 "2011-07-12T16:09:05Z")

</div>

Hello!

On Tue, Jul 12, 2011 at 09:31:07PM +0800, 杨镭 wrote:

> After reload, all the worker processes, including newly forked ones, goes  
> straight to 100% CPU:

[…]

> Also, we took backtrace for cache manger process:
> 
> Attaching to process 17306  
> ngx\_http\_file\_cache\_expire (data=) at  
> src/http/ngx\_http\_file\_cache.c:1096  
> 1096 if (fcn-\>count == 0) {  
> (gdb) bt  
> #0 ngx\_http\_file\_cache\_expire (data=) at  
> src/http/ngx\_http\_file\_cache.c:1096

Could you please show

p \*fcn

?

I think I see the problem, but just to make sure.

If you are able to reproduce the problem please try the following  
patch:

diff --git a/src/http/ngx\_http\_file\_cache.c  
b/src/http/ngx\_http\_file\_cache.c  
— a/src/http/ngx\_http\_file\_cache.c  
+++ b/src/http/ngx\_http\_file\_cache.c  
@@ -1099,7 +1099,8 @@ ngx\_http\_file\_cache\_expire(ngx\_http\_file  
}

```
     if (fcn->deleting) {

```

- 

```
       continue;

```

- 

```
       wait = 1;

```

- 

```
       break;
   }

   p = ngx_hex_dump(key, (u_char *) &fcn->node.key,

```

Maxim D.

---

<div class="post-metadata">

**Author:** ![SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/91b2a8/32.png) [@SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/u/SSSSSSS_SS_SSS)\
**Post date:** [July 13, 2011, 10:21am UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358/3 "2011-07-13T10:21:40Z")

</div>

Hi,

we didn’t take core dump. If we can reproduce the problem, I’ll bring  
you  
the p \*fcn content.

---

<div class="post-metadata">

**Author:** ![SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/91b2a8/32.png) [@SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/u/SSSSSSS_SS_SSS)\
**Post date:** [July 19, 2011, 8:16am UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358/4 "2011-07-19T08:16:52Z")

</div>

Hi,

we reproduced the problem and below is the content of fcn:

(gdb) p \*fcn  
$1 = {node = {key = 2417939894599905030, left = 0x2b822d64f780, right =  
0x2b822ada9a00, parent = 0x2b822bac7080, color = 0 ‘\000’,  
data = 0 ‘\000’}, queue = {prev = 0x2b822afd63a8, next =  
0x2b822ad45040}, key = “\177\215\220\215h!?T”, count = 1, uses = 1,  
valid\_msec = 0, error = 0, exists = 1, updating = 0, deleting = 1,  
uniq =  
7209021, expire = 1311055359, valid\_sec = 0,  
body\_start = 905, fs\_size = 2}  
(gdb)

So I guess we should apply the patch?

---

<div class="post-metadata">

**Author:** ![SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/letter_avatar_proxy/v4/letter/s/91b2a8/32.png) [@SSSSSSS\_SS\_SSS](https://www.ruby-forum.com/u/SSSSSSS_SS_SSS)\
**Post date:** [July 19, 2011, 8:42am UTC](https://www.ruby-forum.com/t/after-reload-nginxs-cpu-usage-jumped-to-100-percent-backtrace-provided/209358/5 "2011-07-19T08:42:53Z")

</div>

Hello!

On Tue, Jul 19, 2011 at 02:16:25PM +0800, 杨镭 wrote:

> 7209021, expire = 1311055359, valid\_sec = 0,  
> body\_start = 905, fs\_size = 2}  
> (gdb)
> 
> So I guess we should apply the patch?

Yes, this is exactly the case I was thinking about.

With fcn-\>deleting == 1 cache manger will loop waiting for cache  
item to be actually deleted, but it’s not going to happen as cache  
manager holds cache lock.

Maxim D.

> > On Tue, Jul 12, 2011 at 10:08 PM, Maxim D. [removed\_email\_address@domain.invalid](mailto:removed_email_address@domain.invalid) wrote:
> > 
> > > - 
> > > 
> > > ```
> > > break;
> > > 
> > > ```
> > > 
> > > [mailman.nginx.org archive](http://nginx.org/mailman/listinfo/nginx)  
> > > –  
> > > lei yang