request never read by nginx

[Marc VERRIERE]

Hello,

First, sorry for my english, it isn't my native language.

I try to improve the WebDav module, and some requests are never read by nginx.

I have seen this bug on nginx-0.7.67 and nginx-1.1.0 (and I never try under other release).

Here is an extract from the output of tcpdump (the last PROPFIND request is never read by nginx) :

10:23:48.605451 IP localhost.localdomain.8084 > localhost.localdomain.49989: Flags [R], seq 2166411627, win 0, length 0
E..(..@.@.<............E. .k....P...|x..
10:23:48.605542 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [S], seq 1181349717, win 32792, options [mss 16396,sackOK,TS val 190837735 ecr 0,nop,wscale 7], length 0
E..<..@.@.8..........9..Fi.U.........0....@....
._..........
10:23:48.605555 IP localhost.localdomain.8084 > localhost.localdomain.54073: Flags [S.], seq 1187600847, ack 1181349718, win 32768, options [mss 16396,sackOK,TS val 190837735 ecr 190837735,nop,wscale 7], length 0
E..<..@.@.<............9F.Y.Fi.V.....0....@....
._..._......
10:23:48.605571 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags ., ack 1, win 257, options [nop,nop,TS val 190837735 ecr 190837735], length 0
E..4..@.@.8..........9..Fi.VF.Y......(.....
._..._..
10:23:48.605599 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [P.], seq 1:184, ack 1, win 257, options [nop,nop,TS val 190837735 ecr 190837735], length 183
E.....@.@.7W.........9..Fi.VF.Y............
._..._..PROPFIND /webserv/ HTTP/1.1
User-Agent: davfs2/1.4.6 neon/0.29.3
Connection: TE
TE: trailers
Host: 127.0.0.1:8084
Depth: 1
Content-Length: 286
Content-Type: application/xml

10:23:48.605608 IP localhost.localdomain.8084 > localhost.localdomain.54073: Flags ., ack 184, win 265, options [nop,nop,TS val 190837735 ecr 190837735], length 0
...4.7@..(.............9F.Y.Fi.
._..._..
10:23:48.605619 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [P.], seq 184:470, ack 1, win 257, options [nop,nop,TS val 190837735 ecr 190837735], length 286
F.Y......F...........9..Fi.
._..._..<?xml version="1.0" encoding="utf-8"?>
<propfind xmlns="DAV:"><prop>
<getetag xmlns="DAV:"/>
<getcontentlength xmlns="DAV:"/>
<creationdate xmlns="DAV:"/>
<getlastmodified xmlns="DAV:"/>
<resourcetype xmlns="DAV:"/>
<executable xmlns="​http://apache.org/dav/props/"/>
</prop></propfind>

10:23:48.605625 IP localhost.localdomain.8084 > localhost.localdomain.54073: Flags ., ack 470, win 273, options [nop,nop,TS val 190837735 ecr 190837735], length 0
E..4.8@.@..............9F.Y.Fi.+.....(.....
._..._..
10:23:48.605959 IP localhost.localdomain.8084 > localhost.localdomain.54073: Flags [P.], seq 1:545, ack 470, win 273, options [nop,nop,TS val 190837735 ecr 190837735], length 544
E..T.9@.@..h...........9F.Y.Fi.+.....I.....
._..._..HTTP/1.1 207 Multi Status
Server: nginx/1.1.0
Date: Tue, 16 Aug 2011 08:23:48 GMT
Content-Length: 412
Connection: keep-alive

<?xml version="1.0"?>
<multistatus xmlns:D:="DAV:"><response><href>/webserv/</href><propstat><prop><getlastmodified>Tue, 16 Aug 2011 8:20:28 GMT</getlastmodified><ressourcetype><collection/></ressourcetype></prop><status>HTTP/1.1 200 OK</status></propstat><propstat><prop><getetag/><getcontentlength/><creationdate/><executable/></prop><status>HTTP/1.1 404 NOT FOUND</status></propstat></response></multistatus>

10:23:48.605971 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags ., ack 545, win 265, options [nop,nop,TS val 190837735 ecr 190837735], length 0
E..4..@.@.8..........9..Fi.+F.[.... .(.....
._..._..
10:24:17.725830 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [P.], seq 470:653, ack 545, win 265, options [nop,nop,TS val 190840647 ecr 190837735], length 183
E.....@.@.7T.........9..Fi.+F.[.... .......
._.G._..PROPFIND /webserv/ HTTP/1.1
User-Agent: davfs2/1.4.6 neon/0.29.3
Connection: TE
TE: trailers
Host: 127.0.0.1:8084
Depth: 1
Content-Length: 286
Content-Type: application/xml

10:24:17.725859 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [P.], seq 653:939, ack 545, win 265, options [nop,nop,TS val 190840647 ecr 190837735], length 286
E..R..@.@.6..........9..Fi..F.[.... .F.....
._.G._..<?xml version="1.0" encoding="utf-8"?>
<propfind xmlns="DAV:"><prop>
<getetag xmlns="DAV:"/>
<getcontentlength xmlns="DAV:"/>
<creationdate xmlns="DAV:"/>
<getlastmodified xmlns="DAV:"/>
<resourcetype xmlns="DAV:"/>
<executable xmlns="​http://apache.org/dav/props/"/>
</prop></propfind>

10:24:17.772610 IP localhost.localdomain.8084 > localhost.localdomain.54073: Flags ., ack 939, win 290, options [nop,nop,TS val 190840651 ecr 190840647], length 0
E..4.:@.@..............9F.[.Fi.....".(.....
._.K._.G
10:24:47.752676 IP localhost.localdomain.54073 > localhost.localdomain.8084: Flags [F.], seq 939, ack 545, win 265, options [nop,nop,TS val 190843649 ecr 190840651], length 0
E..4..@.@.8 .........9..Fi..F.[.... .(.....
.`..._.K
10:24:47.752935 IP localhost.localdomain.54079 > localhost.localdomain.8084: Flags [S], seq 2097184487, win 32792, options [mss 16396,sackOK,TS val 190843650 ecr 0,nop,wscale 7], length 0
E..<u.@.@............?..}.~..........0....@....
.`..........
10:24:47.752951 IP localhost.localdomain.8084 > localhost.localdomain.54079: Flags [S.], seq 2103944207, ack 2097184488, win 32768, options [mss 16396,sackOK,TS val 190843650 ecr 190843650,nop,wscale 7], length 0
E..<..@.@.<............?}g..}.~......0....@....
..........
10:24:47.752966 IP localhost.localdomain.54079 > localhost.localdomain.8084: Flags ., ack 1, win 257, options [nop,nop,TS val 190843650 ecr 190843650], length 0
E..4u.@.@............?..}.~.}g.......(.....
......
10:24:47.752997 IP localhost.localdomain.54079 > localhost.localdomain.8084: Flags [P.], seq 1:129, ack 1, win 257, options [nop,nop,TS val 190843650 ecr 190843650], length 128
E...u.@.@..Z.........?..}.~.}g.............
......MKCOL /webserv/directory/ HTTP/1.1
User-Agent: davfs2/1.4.6 neon/0.29.3
Connection: TE
TE: trailers
Host: 127.0.0.1:8084

10:24:47.753005 IP localhost.localdomain.8084 > localhost.localdomain.54079: Flags ., ack 129, win 265, options [nop,nop,TS val 190843650 ecr 190843650], length 0
E..4..@.@..............?}g..}..h... .(.....
......
10:24:47.753204 IP localhost.localdomain.8084 > localhost.localdomain.54079: Flags [P.], seq 1:186, ack 129, win 265, options [nop,nop,TS val 190843650 ecr 190843650], length 185
E.....@.@..............?}g..}..h... .......
......HTTP/1.1 201 Created
Server: nginx/1.1.0
Date: Tue, 16 Aug 2011 08:24:47 GMT
Location: ​http://127.0.0.1:8084/webserv/directory
Transfer-Encoding: chunked
Connection: keep-alive

[Maxim Dounin]

This looks like problem in your code, not in nginx. If you need help, please ask in nginx-devel@ mailing list.

[Marc VERRIERE]

I think is not my code, because the access log show the problem :

127.0.0.1 - - [16/Aug/2011:11:41:11 +0200] "OPTIONS /webserv/ HTTP/1.1" 200 0 "-" "davfs2/1.4.6 neon/0.29.3"
127.0.0.1 - - [16/Aug/2011:11:41:42 +0200] "USERINFO /webserv/ HTTP/1.1" 405 172 "-" "davfs2/1.4.6 neon/0.29.3"

But two PROPFIND requests are sending by the client between OPTIONS and USERINFO requests, so it isn't a problem with the module...

[Maxim Dounin]

If you think the problem is not in your code - please reproduce it with official nginx code (i.e. without any patches / 3rd party modules).

[Marc VERRIERE]

WebDav module

[Marc VERRIERE]

nginx request source (for multi status)

[Marc VERRIERE]

Oops I forgot the code... I sent you the sources

[Marc VERRIERE]

the command to launch the tests :
while [ 1 ]; do ./objs/nginx -p /home/mverrier/nginx-1.1.0/ -c conf/nginx.conf;sleep 1;echo -e "utilisateur\nmotdepasse" | mount.davfs ​http://127.0.0.1:8084/webserv/ /media/webdav/;sleep 1;umount /media/webdav;objs/nginx -s stop;make -j 5;done;

So, I seen the bug (maybe) 1% of time with this command