Long URLs cause nginx to hang

Hey everyone,

I’m having strange issues with very long url’s under Nginx 1.0.1 (also
tested under 0.8.54). Certain URL’s with a large number of GET
parameters are failing. I wrote a quick test script which only prints 1
line (php), and added a massive GET parameter:

https://test/test.php?blah=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa

This causes Nginx to hang indefinitely, the client receives absolutely
no data (verified by tcpdump). Though, if I cut the parameter in half,
it loads instantly. Is there a configuration directive I need to tweak
in order to handle these massive URL’s?

Thanks!

Ben

Posted at Nginx Forum:

update: to rule out fastcgi/php I ran the same test against a basic HTML
file with the same GET parameter, same problem.

Posted at Nginx Forum:

On Fri, May 06, 2011 at 01:37:17PM -0400, uid_b wrote:

update: to rule out fastcgi/php I ran the same test against a basic HTML
file with the same GET parameter, same problem.

Could you create a debug log of the HTML files request ?
http://nginx.org/en/docs/debugging_log.html


Igor S.

On Fri, May 06, 2011 at 02:56:10PM -0400, uid_b wrote:

I get 2 different outputs, depending on whether the connection is SSL or
not

2011/05/06 12:54:09 [debug] 13267#0: 69 http header: “User-Agent:
Mozilla/5.0 (X11; Linux x86_64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1”
2011/05/06 12:54:09 [debug] 13267#0: 69 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,
/
;q=0.8"

Did you try other browser ?


Igor S.

Igor S. Wrote:

I get 2 different outputs, depending on whether the connection is SSL or
not

Non-SSL:
2011/05/06 12:52:44 [debug] 13267#0: *48 accept: 192.168.10.21 fd:3
2011/05/06 12:52:44 [debug] 13267#0: *48 event timer add: 3:
120000:1304708084457
2011/05/06 12:52:44 [debug] 13267#0: *48 epoll add event: fd:3 op:1
ev:80000001

SSL:
2011/05/06 12:48:49 [debug] 12804#0: *16 accept: 192.168.10.21 fd:3
2011/05/06 12:48:49 [debug] 12804#0: *16 event timer add: 3:
120000:1304707849612
2011/05/06 12:48:49 [debug] 12804#0: *16 epoll add event: fd:3 op:1
ev:80000001
2011/05/06 12:48:49 [debug] 12804#0: *16 malloc: 0000000001440680:1296
2011/05/06 12:48:49 [debug] 12804#0: *16 posix_memalign:
000000000138BEB0:256 @16
2011/05/06 12:48:49 [debug] 12804#0: *16 malloc: 0000000001229710:1024
2011/05/06 12:48:49 [debug] 12804#0: *16 posix_memalign:
000000000151E9E0:4096 @16
2011/05/06 12:48:49 [debug] 12804#0: *16 http check ssl handshake
2011/05/06 12:48:49 [debug] 12804#0: *16 https ssl handshake: 0x16
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL server name: “seismo”
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL_do_handshake: -1
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL_get_error: 2
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL handshake handler: 0
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL_do_handshake: 1
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL: TLSv1, cipher:
“DHE-RSA-AES256-SHA SSLv3 Kx=DH Au=RSA Enc=AES(256) Mac=SHA1”
2011/05/06 12:48:49 [debug] 12804#0: *16 http process request line
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL_read: -1
2011/05/06 12:48:49 [debug] 12804#0: *16 SSL_get_error: 2

If I remove the massive GET parameter:
2011/05/06 12:54:09 [debug] 13267#0: *69 accept: 192.168.10.21 fd:17
2011/05/06 12:54:09 [debug] 13267#0: *69 event timer add: 17:
120000:1304708169332
2011/05/06 12:54:09 [debug] 13267#0: *69 epoll add event: fd:17 op:1
ev:80000001
2011/05/06 12:54:09 [debug] 13267#0: *69 malloc: 00000000019EEE70:1296
2011/05/06 12:54:09 [debug] 13267#0: *69 posix_memalign:
0000000001B9B460:256 @16
2011/05/06 12:54:09 [debug] 13267#0: *69 malloc: 00000000019E0710:1024
2011/05/06 12:54:09 [debug] 13267#0: *69 posix_memalign:
0000000001C0AA40:4096 @16
2011/05/06 12:54:09 [debug] 13267#0: *69 http process request line
2011/05/06 12:54:09 [debug] 13267#0: *69 recv: fd:17 645 of 1024
2011/05/06 12:54:09 [debug] 13267#0: *69 http request line: “GET
/test.html HTTP/1.1”
2011/05/06 12:54:09 [debug] 13267#0: *69 http uri: “/test.html”
2011/05/06 12:54:09 [debug] 13267#0: *69 http args: “”
2011/05/06 12:54:09 [debug] 13267#0: *69 http exten: “html”
2011/05/06 12:54:09 [debug] 13267#0: *69 http process request header
line
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Host: seismo”
2011/05/06 12:54:09 [debug] 13267#0: 69 http header: “User-Agent:
Mozilla/5.0 (X11; Linux x86_64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1”
2011/05/06 12:54:09 [debug] 13267#0: 69 http header: "Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,
/
;q=0.8"
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Accept-Language:
en-us,en;q=0.5”
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Accept-Encoding:
gzip, deflate”
2011/05/06 12:54:09 [debug] 13267#0: 69 http header: "Accept-Charset:
ISO-8859-1,utf-8;q=0.7,
;q=0.7"
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Keep-Alive: 115”
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Connection:
keep-alive”
2011/05/06 12:54:09 [debug] 13267#0: *69 http header: “Cookie:
PHPSESSID=l3a89kpj6j0es6qbkkf1nd1p80;
__utma=16576436.82209771.1304707931.1304707931.1304707931.1;
__utmb=16576436.2.10.1304707931; __utmc=16576436;
__utmz=16576436.1304707931.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none)”
2011/05/06 12:54:09 [debug] 13267#0: *69 http header:
“If-Modified-Since: Fri, 06 May 2011 18:36:06 GMT”
2011/05/06 12:54:09 [debug] 13267#0: *69 http header done
2011/05/06 12:54:09 [debug] 13267#0: *69 event timer del: 17:
1304708169332
2011/05/06 12:54:09 [debug] 13267#0: *69 generic phase: 0
2011/05/06 12:54:09 [debug] 13267#0: *69 rewrite phase: 1
2011/05/06 12:54:09 [debug] 13267#0: *69 test location: “/”
2011/05/06 12:54:09 [debug] 13267#0: *69 test location: ~ “.php”
2011/05/06 12:54:09 [debug] 13267#0: *69 test location: ~ “/.ht”
2011/05/06 12:54:09 [debug] 13267#0: *69 using configuration “/sparkle”
2011/05/06 12:54:09 [debug] 13267#0: *69 http cl:-1 max:10485760
2011/05/06 12:54:09 [debug] 13267#0: *69 rewrite phase: 3
2011/05/06 12:54:09 [debug] 13267#0: *69 post rewrite phase: 4
2011/05/06 12:54:09 [debug] 13267#0: *69 generic phase: 5
2011/05/06 12:54:09 [debug] 13267#0: *69 generic phase: 6
2011/05/06 12:54:09 [debug] 13267#0: *69 generic phase: 7
2011/05/06 12:54:09 [debug] 13267#0: *69 access phase: 8
2011/05/06 12:54:09 [debug] 13267#0: *69 access phase: 9
2011/05/06 12:54:09 [debug] 13267#0: *69 post access phase: 10
2011/05/06 12:54:09 [debug] 13267#0: *69 try files phase: 11
2011/05/06 12:54:09 [debug] 13267#0: *69 http script var: “/test.html”
2011/05/06 12:54:09 [debug] 13267#0: *69 try to use file: “/test.html”
“/var/www/test.html”
2011/05/06 12:54:09 [debug] 13267#0: *69 try file uri: “/test.html”
2011/05/06 12:54:09 [debug] 13267#0: *69 content phase: 12
2011/05/06 12:54:09 [debug] 13267#0: *69 content phase: 13
2011/05/06 12:54:09 [debug] 13267#0: *69 content phase: 14
2011/05/06 12:54:09 [debug] 13267#0: *69 content phase: 15
2011/05/06 12:54:09 [debug] 13267#0: *69 content phase: 16
2011/05/06 12:54:09 [debug] 13267#0: *69 http filename:
“/var/www/test.html”
2011/05/06 12:54:09 [debug] 13267#0: *69 add cleanup: 0000000001C0B638
2011/05/06 12:54:09 [debug] 13267#0: *69 http static fd: 18
2011/05/06 12:54:09 [debug] 13267#0: *69 http set discard body
2011/05/06 12:54:09 [debug] 13267#0: *69 http ims:1304706966
lm:1304706966
2011/05/06 12:54:09 [debug] 13267#0: *69 HTTP/1.1 304 Not Modified
Server: nginx
Date: Fri, 06 May 2011 18:54:09 GMT
Last-Modified: Fri, 06 May 2011 18:36:06 GMT
Connection: keep-alive

2011/05/06 12:54:09 [debug] 13267#0: *69 write new buf t:1 f:0
0000000001C0B7D0, pos 0000000001C0B7D0, size: 151 file: 0, size: 0
2011/05/06 12:54:09 [debug] 13267#0: *69 http write filter: l:1 f:0
s:151
2011/05/06 12:54:09 [debug] 13267#0: *69 http write filter limit 0
2011/05/06 12:54:09 [debug] 13267#0: *69 writev: 151
2011/05/06 12:54:09 [debug] 13267#0: *69 http write filter
0000000000000000
2011/05/06 12:54:09 [debug] 13267#0: *69 http finalize request: 0,
“/sparkle/test.html?” a:1, c:1
2011/05/06 12:54:09 [debug] 13267#0: *69 set http keepalive handler
2011/05/06 12:54:09 [debug] 13267#0: *69 http close request
2011/05/06 12:54:09 [debug] 13267#0: *69 http log handler
2011/05/06 12:54:09 [debug] 13267#0: *69 run cleanup: 0000000001C0B638
2011/05/06 12:54:09 [debug] 13267#0: *69 file cleanup: fd:18
2011/05/06 12:54:09 [debug] 13267#0: *69 free: 0000000001C0AA40, unused:
273
2011/05/06 12:54:09 [debug] 13267#0: *69 event timer add: 17:
2000:1304708051332
2011/05/06 12:54:09 [debug] 13267#0: *69 free: 00000000019EEE70
2011/05/06 12:54:09 [debug] 13267#0: *69 free: 00000000019E0710
2011/05/06 12:54:09 [debug] 13267#0: *69 hc free: 0000000000000000 0
2011/05/06 12:54:09 [debug] 13267#0: *69 hc busy: 0000000000000000 0
2011/05/06 12:54:09 [debug] 13267#0: *69 tcp_nodelay
2011/05/06 12:54:09 [debug] 13267#0: *69 reusable connection: 1
2011/05/06 12:54:09 [debug] 13267#0: *69 post event 00000000019EE768
2011/05/06 12:54:09 [debug] 13267#0: *69 delete posted event
00000000019EE768
2011/05/06 12:54:09 [debug] 13267#0: *69 http keepalive handler
2011/05/06 12:54:09 [debug] 13267#0: *69 malloc: 00000000019E0710:1024
2011/05/06 12:54:09 [debug] 13267#0: *69 recv: fd:17 -1 of 1024
2011/05/06 12:54:09 [debug] 13267#0: *69 recv() not ready (11: Resource
temporarily unavailable)
2011/05/06 12:54:11 [debug] 13267#0: *69 event timer del: 17:
1304708051332
2011/05/06 12:54:11 [debug] 13267#0: *69 http keepalive handler
2011/05/06 12:54:11 [debug] 13267#0: *69 close http connection: 17
2011/05/06 12:54:11 [debug] 13267#0: *69 reusable connection: 0
2011/05/06 12:54:11 [debug] 13267#0: *69 free: 00000000019E0710
2011/05/06 12:54:11 [debug] 13267#0: *69 free: 0000000000000000
2011/05/06 12:54:11 [debug] 13267#0: *69 free: 0000000001B9AC50, unused:
8
2011/05/06 12:54:11 [debug] 13267#0: *69 free: 0000000001B9B460, unused:
128

Posted at Nginx Forum:

This appears to be an issue with our VPN, I have no idea why everything
works except for massive URL’s but I don’t think it’s related to nginx
in any way.

Thanks for your help!

Posted at Nginx Forum:

On Fri, May 06, 2011 at 03:39:50PM -0400, uid_b wrote:

This appears to be an issue with our VPN, I have no idea why everything
works except for massive URL’s but I don’t think it’s related to nginx
in any way.

Try to search for “path mtu discovery vpn”.


Igor S.

On Fri, May 06, 2011 at 02:56:10PM -0400, uid_b wrote:

I get 2 different outputs, depending on whether the connection is SSL or
not

Non-SSL:
2011/05/06 12:52:44 [debug] 13267#0: *48 accept: 192.168.10.21 fd:3
2011/05/06 12:52:44 [debug] 13267#0: *48 event timer add: 3:
120000:1304708084457
2011/05/06 12:52:44 [debug] 13267#0: *48 epoll add event: fd:3 op:1
ev:80000001

nginx does not receive any data and it should close connection after
120s.
Did you run tcpdump on server side ?


Igor S.