SOAP POST request lag

Sun May 17 18:56:55 MSD 2009

Коллеги, кто может подсказать почему возникает лаг в 50 секунд при POST
запросе от SOAP клиента, может ли в этом виноват nginx? При томже запросе
напрямую (то есть без nginx сервера) все работает без проблем.

Debug лог:

2009/05/17 18:43:15 [debug] 20128#0: *598 event timer del: 206:
1242571455407
2009/05/17 18:43:15 [debug] 20128#0: *598 generic phase: 0
2009/05/17 18:43:15 [debug] 20128#0: *598 generic phase: 1
2009/05/17 18:43:15 [debug] 20128#0: *598 find location for
"/webservices.php/user_content"
2009/05/17 18:43:15 [debug] 20128#0: *598 find location: "/"
2009/05/17 18:43:15 [debug] 20128#0: *598 using configuration "/"
2009/05/17 18:43:15 [debug] 20128#0: *598 http cl:258589 max:62914560
2009/05/17 18:43:15 [debug] 20128#0: *598 generic phase: 3
2009/05/17 18:43:15 [debug] 20128#0: *598 post rewrite phase: 4
2009/05/17 18:43:15 [debug] 20128#0: *598 generic phase: 5
2009/05/17 18:43:15 [debug] 20128#0: *598 generic phase: 6
2009/05/17 18:43:15 [debug] 20128#0: *598 access phase: 7
2009/05/17 18:43:15 [debug] 20128#0: *598 access phase: 8
2009/05/17 18:43:15 [debug] 20128#0: *598 access phase: 9
2009/05/17 18:43:15 [debug] 20128#0: *598 post access phase: 10
2009/05/17 18:43:15 [debug] 20128#0: *598 malloc: 000000000094B000:4096
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body preread
819
2009/05/17 18:43:15 [debug] 20128#0: *598 malloc: 000000000118B000:131072
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:3320, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 7664 of 131072
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv 7664
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
250106
2009/05/17 18:43:15 [debug] 20128#0: *598 event timer add: 206:
60000:1242571455407
2009/05/17 18:43:15 [debug] 20128#0: *598 post event 0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 delete posted event
0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:8688, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 8688 of 123408
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv 8688
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
241418
2009/05/17 18:43:15 [debug] 20128#0: *598 event timer: 206, old:
1242571455407, new: 1242571455408
2009/05/17 18:43:15 [debug] 20128#0: *598 post event 0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 delete posted event
0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:4344, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 13032 of 114720
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv
13032
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
228386
2009/05/17 18:43:15 [debug] 20128#0: *598 event timer: 206, old:
1242571455407, new: 1242571455409
2009/05/17 18:43:15 [debug] 20128#0: *598 post event 0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 delete posted event
0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:8688, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 20272 of 101688
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv
20272
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
208114
2009/05/17 18:43:15 [debug] 20128#0: *598 event timer: 206, old:
1242571455407, new: 1242571455409
2009/05/17 18:43:15 [debug] 20128#0: *598 post event 0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 delete posted event
0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:11584, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 11584 of 81416
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv
11584
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
196530
2009/05/17 18:43:15 [debug] 20128#0: *598 event timer: 206, old:
1242571455407, new: 1242571455409
2009/05/17 18:43:15 [debug] 20128#0: *598 post event 0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 delete posted event
0000000000D2B690
2009/05/17 18:43:15 [debug] 20128#0: *598 http read client request body
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: eof:0, avail:4344, err:0
2009/05/17 18:43:15 [debug] 20128#0: *598 recv: fd:206 4344 of 69832
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body recv 4344
2009/05/17 18:43:15 [debug] 20128#0: *598 http client request body rest
192186
2009/05/17 *18:43:15* [debug] 20128#0: *598 event timer: 206, old:
1242571455407, new: 1242571455409
2009/05/17 *18:44:06* [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:06 [debug] 20128#0: *598 recv: eof:0, avail:1448, err:0
2009/05/17 18:44:06 [debug] 20128#0: *598 recv: fd:206 1448 of 65488
2009/05/17 18:44:06 [debug] 20128#0: *598 http client request body recv 1448
2009/05/17 18:44:06 [debug] 20128#0: *598 http client request body rest
190738
2009/05/17 18:44:06 [debug] 20128#0: *598 event timer del: 206:
1242571455407
2009/05/17 18:44:06 [debug] 20128#0: *598 event timer add: 206:
60000:1242571506913
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:2896, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 2896 of 64040
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 2896
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
187842
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507013
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:2896, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 4344 of 61144
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 4344
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
183498
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:5792, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 5792 of 56800
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 5792
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
177706
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:1448, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 1448 of 51008
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 1448
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
176258
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:5792, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 5792 of 49560
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 5792
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
170466
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:2896, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 2896 of 43768
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 2896
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
167570
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:5296, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 5296 of 40872
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 5296
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
162274
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:8688, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 8688 of 35576
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 8688
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
153586
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507014
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:1448, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 7240 of 26888
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 7240
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
146346
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507015
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:2896, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 7240 of 19648
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 7240
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
139106
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507015
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:1448, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 8688 of 12408
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 8688
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
130418
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507015
2009/05/17 18:44:07 [debug] 20128#0: *598 http read client request body
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:5792, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 3720 of 3720
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 3720
2009/05/17 18:44:07 [debug] 20128#0: *598 add cleanup: 000000000094B238
2009/05/17 18:44:07 [debug] 20128#0: *598 hashed path:
/var/nginx/client_body_temp/0000000003
2009/05/17 18:44:07 [debug] 20128#0: *598 temp fd:211
2009/05/17 18:44:07 [warn] 20128#0: *598 a client request body is buffered
to a temporary file /var/nginx/client_body_temp/0000000003, client: x.x.x.x,
server: example.com, request: "POST /webservices.php/user_content HTTP/1.1",
host: "example.com"
2009/05/17 18:44:07 [debug] 20128#0: *598 write: 211, 000000000118B000,
131072, 0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: eof:0, avail:2072, err:0
2009/05/17 18:44:07 [debug] 20128#0: *598 recv: fd:206 2072 of 126698
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body recv 2072
2009/05/17 18:44:07 [debug] 20128#0: *598 http client request body rest
124626
2009/05/17 18:44:07 [debug] 20128#0: *598 event timer: 206, old:
1242571506913, new: 1242571507015
2009/05/17 18:45:06 [debug] 20128#0: *598 event timer del: 206:
1242571506913
2009/05/17 18:45:06 [debug] 20128#0: *598 http finalize request: 408,
"/webservices.php/user_content?"
2009/05/17 18:45:06 [debug] 20128#0: *598 http close request
2009/05/17 18:45:06 [debug] 20128#0: *598 http log handler
2009/05/17 18:45:06 [debug] 20128#0: *598 run cleanup: 000000000094B238
2009/05/17 18:45:06 [debug] 20128#0: *598 file cleanup: fd:211
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 000000000118B000
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 000000000094A000, unused: 8
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 000000000094B000, unused:
3344
2009/05/17 18:45:06 [debug] 20128#0: *598 close http connection: 206
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 00000000005EA400
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 00000000005E2800
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 0000000000918600, unused: 8
2009/05/17 18:45:06 [debug] 20128#0: *598 free: 0000000000918700, unused:
112
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://nginx.org/pipermail/nginx-ru/attachments/20090517/358b2aac/attachment.html>