hi all, [nginx]"accept_mutex on" cause 1s delay
lx
lxlenovostar at gmail.com
Mon Nov 11 03:26:30 UTC 2019
hi all:
I use nginx-1.16.0, nginx is running on X86 embedded devices. The
embedded device has 4 CPU, CPU type is: "Intel(R) Atom(TM) CPU D525 @
1.80GHz".
When I use "accpet_mutex on", nginx use 1 secod for get static file.
*events { use epoll; accept_mutex on; worker_connections 10240;}*
The debug log is:
###########################################################################
2019/11/08 17:08:10 [debug] 2552#2552: *1 post access phase:
12
2019/11/08 17:08:10 [debug] 2552#2552: *1 generic phase:
13
2019/11/08 17:08:10 [debug] 2552#2552: *1 generic phase:
14
2019/11/08 17:08:10 [debug] 2552#2552: *1 http script copy: "http://
"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http script var: "
pcdnapkwsdl2.com.cn
"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http script copy:
"/"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http script var:
"appstore/developer/soft/20191008/201910081449521157660_v2_820_811.patch"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http init upstream, client timer:
0
2019/11/08 17:08:10 [debug] 2552#2552: *1 epoll add event: fd:15 op:3
ev:80002005
2019/11/08 17:08:10 [debug] 2552#2552: *1 http cache key: "
http://pcdnapkwsdl2.vivo.com.cn
"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http cache key:
"/appstore/developer/soft/20191008/201910081449521157660_v2_820_811.patch"
2019/11/08 17:08:10 [debug] 2552#2552: *1 add cleanup:
00000000026C46C0
2019/11/08 17:08:10 [debug] 2552#2552: shmtx
lock
2019/11/08 17:08:10 [debug] 2552#2552: shmtx
unlock
2019/11/08 17:08:10 [debug] 2552#2552: *1 http file cache exists: 0
e:1
2019/11/08 17:08:10 [debug] 2552#2552: *1 cache file:
"/tmp/storage/youyu/ikcdndata/wangsu2/wan1/p2p_proxy/cache/c/df/468f0ede6aa8ba9073f9a989b8377dfc"
2019/11/08 17:08:10 [debug] 2552#2552: *1 add cleanup:
00000000026C4740
2019/11/08 17:08:10 [debug] 2552#2552: *1 http file cache fd:
16
2019/11/08 17:08:10 [debug] 2552#2552: *1 malloc:
00000000026C48D0:4096
2019/11/08 17:08:10 [debug] 2552#2552: *1 thread read: 16,
00000000026C48D0, 4096,
0
2019/11/08 17:08:10 [debug] 2552#2552: task #0 added to thread pool
"default"
2019/11/08 17:08:10 [debug] 2552#2552: *1 http upstream cache:
-2
2019/11/08 17:08:10 [debug] 2552#2552: *1 http finalize request: -4, "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_811
2019/11/08 17:08:10 [debug] 2552#2552: *1 http request count:2
blk:1
2019/11/08 17:08:10 [debug] 2552#2552: worker
cycle
2019/11/08 17:08:10 [debug] 2552#2552: accept mutex
locked
2019/11/08 17:08:10 [debug] 2552#2552: epoll timer:
-1
2019/11/08 17:08:11 [debug] 2552#2552: epoll: fd:15 ev:0004
d:00007F026302A3F0
2019/11/08 17:08:11 [debug] 2552#2552: *1 post event
00007F0262E48190
2019/11/08 17:08:11 [debug] 2552#2552: timer delta:
533
2019/11/08 17:08:11 [debug] 2552#2552: posted event
00007F0262E48190
2019/11/08 17:08:11 [debug] 2552#2552: *1 delete posted event
00007F0262E48190
2019/11/08 17:08:11 [debug] 2552#2552: *1 http run request: "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_811.patch
?"
2019/11/08 17:08:11 [debug] 2552#2552: worker
cycle
2019/11/08 17:08:11 [debug] 2552#2552: accept mutex
locked
2019/11/08 17:08:11 [debug] 2552#2552: epoll timer:
-1
2019/11/08 17:08:11 [debug] 2552#2564: run task #0 in thread pool
"default"
2019/11/08 17:08:11 [debug] 2552#2564: thread read
handler
2019/11/08 17:08:11 [debug] 2554#2554: timer delta: 809
2019/11/08 17:08:11 [debug] 2554#2554: worker cycle
2019/11/08 17:08:11 [debug] 2554#2554: accept mutex lock failed:
02019/11/08 17:08:11 [debug] 2554#2554: epoll timer:
500
2019/11/08 17:08:11 [debug] 2553#2553: timer delta: 809
2019/11/08 17:08:11 [debug] 2553#2553: worker cycle
2019/11/08 17:08:11 [debug] 2553#2553: accept mutex lock failed: 0
2019/11/08 17:08:11 [debug] 2553#2553: epoll timer: 500
2019/11/08 17:08:11 [debug] 2555#2555: timer delta: 811
2019/11/08 17:08:11 [debug] 2555#2555: worker
cycle
2019/11/08 17:08:11 [debug] 2555#2555: accept mutex lock failed:
0
2019/11/08 17:08:11 [debug] 2555#2555: epoll timer:
500
2019/11/08 17:08:11 [debug] 2552#2564: pread: 4096 (err: 0) of 4096
@0
2019/11/08 17:08:11 [debug] 2552#2564: complete task #0 in thread pool
"default"
2019/11/08 17:08:11 [debug] 2552#2552: epoll: fd:11 ev:0001
d:000000000086FF20
2019/11/08 17:08:11 [debug] 2552#2552: post event 000000000086FEC0
2019/11/08 17:08:11 [debug] 2552#2552: timer delta: 343
2019/11/08 17:08:11 [debug] 2552#2552: posted event 000000000086FEC0
2019/11/08 17:08:11 [debug] 2552#2552: delete posted event
000000000086FEC0
2019/11/08 17:08:11 [debug] 2552#2552: thread pool handler2019/11/08
17:08:11 [debug] 2552#2552: run completion handler for task
#0
2019/11/08 17:08:11 [debug] 2552#2552: *1 http file cache thread: "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_811.patch
?"
2019/11/08 17:08:11 [debug] 2552#2552: *1 thread read: 16,
00000000026C48D0, 4096, 0
2019/11/08 17:08:11 [debug] 2552#2552: *1 http upstream cache: 0
2019/11/08 17:08:11 [debug] 2552#2552: *1 posix_memalign:
00000000026C58E0:4096 @16
2019/11/08 17:08:11 [debug] 2552#2552: *1 http proxy status 200 "200 OK"
###########################################################################
If I don't use "accpet_mutex on" , I can get http response quickly. The
debug log is:
###########################################################################
2019/11/08 17:14:34 [debug] 23726#23726: *1 malloc:
000000000226E8D0:4096
2019/11/08 17:14:34 [debug] 23726#23726: *1 thread read: 17,
000000000226E8D0, 4096,
0
2019/11/08 17:14:34 [debug] 23726#23726: task #0 added to thread pool
"default"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http upstream cache:
-2
2019/11/08 17:14:34 [debug] 23726#23795: run task #0 in thread pool
"default"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http finalize request: -4, "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_8
2019/11/08 17:14:34 [debug] 23726#23795: thread read
handler
2019/11/08 17:14:34 [debug] 23726#23726: *1 http request count:2
blk:1
2019/11/08 17:14:34 [debug] 23726#23726: timer delta:
2
2019/11/08 17:14:34 [debug] 23726#23795: pread: 4096 (err: 0) of 4096
@0
2019/11/08 17:14:34 [debug] 23726#23726: worker
cycle
2019/11/08 17:14:34 [debug] 23726#23795: complete task #0 in thread pool
"default"
2019/11/08 17:14:34 [debug] 23726#23726: epoll timer:
-1
2019/11/08 17:14:34 [debug] 23726#23726: epoll: fd:16 ev:0004
d:00007F3D265033F0
2019/11/08 17:14:34 [debug] 23726#23726: *1 http run request: "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_811.patch
?
2019/11/08 17:14:34 [debug] 23726#23726: timer delta:
0
2019/11/08 17:14:34 [debug] 23726#23726: worker
cycle
2019/11/08 17:14:34 [debug] 23726#23726: epoll timer:
-1
2019/11/08 17:14:34 [debug] 23726#23726: epoll: fd:13 ev:0001
d:000000000086FF20
2019/11/08 17:14:34 [debug] 23726#23726: thread pool
handler
2019/11/08 17:14:34 [debug] 23726#23726: run completion handler for task
#0
2019/11/08 17:14:34 [debug] 23726#23726: *1 http file cache thread: "/
pcdnapkwsdl2.com.cn/pcdnapkwsdltest.com.cn/appstore/developer/soft/20191008/201910081449521157660_v2_820_811
.
2019/11/08 17:14:34 [debug] 23726#23726: *1 thread read: 17,
000000000226E8D0, 4096,
0
2019/11/08 17:14:34 [debug] 23726#23726: shmtx
lock
2019/11/08 17:14:34 [debug] 23726#23726: shmtx
unlock
2019/11/08 17:14:34 [debug] 23726#23726: *1 http upstream cache:
0
2019/11/08 17:14:34 [debug] 23726#23726: *1 posix_memalign:
000000000226F8E0:4096
@16
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy status 200 "200
OK"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header: "Date: Fri,
08 Nov 2019 07:50:58
GMT"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header:
"Content-Type:
application/octet-stream"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header:
"Content-Length:
40492454"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header: "Connection:
close"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header: "Server:
AliyunOSS"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header:
"x-oss-request-id:
5D9C3B95591574F5686E7B00"
2019/11/08 17:14:34 [debug] 23726#23726: *1 http proxy header:
"Accept-Ranges: bytes"
###########################################################################
How should this problem be analyzed? I am a newcomer to nginx.
Thank you.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mailman.nginx.org/pipermail/nginx/attachments/20191111/1dc5684c/attachment-0001.htm>
More information about the nginx
mailing list