Webdav PUT response confuses Neon

[jswinner]

When sending files to a zope 2.10.6 folder, the write takes many attempts and minutes to complete, using davfs2/neon client.

After a PUT is received from the client, and In response to a HEAD-request for a non-existent resource, the Zope response includes a body, showing up as 404 messages in the z2 log. This is not allowed according to the RFC and seems to confuse neon, causing it to close the connection. This repeats, until for some reason, Zope responds with the correct status OK and then the file get written.

What RFC 2616 says about HEAD and body:

9.4 HEAD

   The HEAD method is identical to GET except that the server MUST NOT
   return a message-body in the response.

[Tres Seaver (tseaver)]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

jswinner wrote:

> When sending files to a zope 2.10.6 folder, the write takes many
> attempts and minutes to complete, using davfs2/neon client.
>
> After a PUT is received from the client, and In response to a HEAD-
> request for a non-existent resource, the Zope response includes a body,
> showing up as 404 messages in the z2 log. This is not allowed according
> to the RFC and seems to confuse neon, causing it to close the
> connection. This repeats, until for some reason, Zope responds with the
> correct status OK and then the file get written.
>
> What RFC 2616 says about HEAD and body:
>
> 9.4 HEAD
>
> The HEAD method is identical to GET except that the server MUST NOT
> return a message-body in the response.
>

I can't reproduce with the Zope 2.10 branch tip using cadaver, which
also uses libneon::

- -----------------------------------------------------------------
$ cd projects/Zope-CVS/Zope-2.10-branch/
$ bin/mkzopeinstance.py -d /tmp/lp239636 -u admin:admin
$ cd /tmp/lp239636/
$ bin/zopectl start
$ bin/zopectl logtail
2008-06-13T10:47:51 INFO ZServer HTTP server started at Fri Jun 13
10:47:51 2008
 Hostname: 0.0.0.0
 Port: 8080
- ------
2008-06-13T10:47:58 INFO Application New disk product detected,
determining if we need to fix up any ZClasses.
- ------
2008-06-13T10:47:58 INFO Zope Ready to handle requests
^c
$ echo "This is a test." > foo.txt
$ cadaver http://localhost:8080/
Authentication required for Zope on server `localhost':
Username: admin
Password:
dav:/> put foo.txt
Uploading foo.txt to `/foo.txt':
Progress: [=============================>] 100.0% of 16 bytes succeeded.
dav:/> cat foo.txt
Displaying `/foo.txt':
This is a test.
dav:/> cat not_there
Displaying `/not_there':
Failed: 404 Not Found
dav:/> ls
Listing collection `/': succeeded.
Coll: Control_Panel 0 Jun 13 10:47
Coll: temp_folder 0 Jun 13 10:47
        acl_users 0 Jun 13 10:47
        browser_id_manager 0 Jun 13 10:47
        error_log 0 Jun 13 10:47
        favicon.ico 22486 Jun 13 10:47
        foo.txt 16 Jun 13 10:50
        index_html 28 Jun 13 10:47
        session_data_manager 0 Jun 13 10:47
        standard_error_message 1227 Jun 13 10:47
        standard_html_footer 18 Jun 13 10:47
        standard_html_header 82 Jun 13 10:47
        standard_template.pt 281 Jun 13 10:47
        virtual_hosting 0 Jun 13 10:47
^D
$ dpkg-query --show libneon27
libneon27 0.27.2-1
$ dpkg-query --show cadaver
cadaver 0.23.0-1
- -----------------------------------------------------------------

If your HEAD request is returning a 404, then you have a different
problem (the resource is not there). AFAICT, the presence of the
response body is contra-spec, but has not caused any other issues that I
know of in the eight years I've been using DAV against Zope.

Tres.
- --
=======================...

[jswinner (jswinner)]

Thanks Tres, I am libneon26, so I will recompile and retest.

Jeff

[jswinner (jswinner)]

No change with the recompile and the problem will not replicate in cadaver because it's not checking for a pre-existing resource like davfs is doing. The precheck can be optioned out in davfs2, but an apache bug comes with it.....

Here more detail:

So the the first PUT, Returns the 404, which makes since since the file does not exist.

JJun 13 20:37:59 office mount.davfs: Sending request headers: HEAD /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host:192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
Jun 13 20:37:59 office mount.davfs: Sending request-line and headers:
Jun 13 20:37:59 office mount.davfs: Connecting to 192.168.0.120
Jun 13 20:37:59 office mount.davfs: Request sent; retry is 0.
Jun 13 20:37:59 office mount.davfs: [status-line] < HTTP/1.1 404 Not Found^M
Jun 13 20:37:59 office mount.davfs: [hdr] Server: Zope/(Zope 2.10.6-final, python 2.4.4, linux2) ZServer/1.1 Plone/3.1.2^M

snipped log
Then the next cycle, note the borked status line

Jun 13 20:37:59 office mount.davfs: Running pre_send hooks
Jun 13 20:37:59 office mount.davfs: Sending request headers: PUT /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host:192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Content-Length: 221691^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
Jun 13 20:37:59 office mount.davfs: Sending request-line and headers:
Jun 13 20:37:59 office mount.davfs: Sending request body:
Jun 13 20:37:59 office mount.davfs: Request sent; retry is 1.
Jun 13 20:37:59 office mount.davfs: [status-line] < <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
Jun 13 20:37:59 office mount.davfs: Aborted request (0): Could not parse response status line
Jun 13 20:37:59 office mount.davfs: Closing connection.
Jun 13 20:37:59 office mount.davfs: Connection closed.
Jun 13 20:37:59 office mount.davfs: Request ends, status 0 class 0xx, error line: Could not parse response status line
Jun 13 20:37:59 office mount.davfs: Running destroy hooks.
Jun 13 20:37:59 office mount.davfs: Request ends.

Davfs retries every 10 sec, until it works finally, note the timestamp shift and the correct status response:

Jun 13 20:40:43 office mount.davfs: Sending request headers: HEAD /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host: 192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
Jun 13 20:40:43 office mount.davfs: Sending request-line and headers:
Jun 13 20:40:43 office mount.davfs: Connecting to 192.168.0.120
Jun 13 20:40:43 office mount.davfs: Request sent; retry is 0.
Jun 13 20:40:43 office mount.davfs: [status-line] < HTTP/1.1 200 OK^M
Jun 13 20:40:43 office mount.davfs: [hdr] Server: Zope/(Zope 2.10.6-final, python 2.4.4, linux2) ZServer/1.1 Plone/3.1.2^M
Jun 13 20:40:43 office mount.davfs: Header Name: [server], Value: [Zope/(Zope 2.10.6-final, python 2.4.4, linux2) ZServer/1.1 Plone/3.1.2]
Jun 13 20:40:43 office mount.davfs: [hdr] Date: Sat, 14 Jun 2008 03:40:44 GMT^M
Jun 13 ...

[Tres Seaver (tseaver)]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

jswinner wrote:
> No change with the recompile and the problem will not replicate in
> cadaver because it's not checking for a pre-existing resource like davfs
> is doing. The precheck can be optioned out in davfs2, but an apache bug
> comes with it.....
>
> Here more detail:
>
> So the the first PUT, Returns the 404, which makes since since the file
> does not exist.

That doesn't happen in Zope: PUT to a non-existent resource works just
fine (assuming no other issue). I assume you meant "HEAD".

> JJun 13 20:37:59 office mount.davfs: Sending request headers: HEAD /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host:192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
> Jun 13 20:37:59 office mount.davfs: Sending request-line and headers:
> Jun 13 20:37:59 office mount.davfs: Connecting to 192.168.0.120
> Jun 13 20:37:59 office mount.davfs: Request sent; retry is 0.
> Jun 13 20:37:59 office mount.davfs: [status-line] < HTTP/1.1 404 Not Found^M
> Jun 13 20:37:59 office mount.davfs: [hdr] Server: Zope/(Zope 2.10.6-final, python 2.4.4, linux2) ZServer/1.1 Plone/3.1.2^M
>
> snipped log
> Then the next cycle, note the borked status line
>
> Jun 13 20:37:59 office mount.davfs: Running pre_send hooks
> Jun 13 20:37:59 office mount.davfs: Sending request headers: PUT /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host:192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Content-Length: 221691^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
> Jun 13 20:37:59 office mount.davfs: Sending request-line and headers:
> Jun 13 20:37:59 office mount.davfs: Sending request body:
> Jun 13 20:37:59 office mount.davfs: Request sent; retry is 1.
> Jun 13 20:37:59 office mount.davfs: [status-line] < <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
> Jun 13 20:37:59 office mount.davfs: Aborted request (0): Could not parse response status line

Would it be correct to assume vfs is leaving the old payload on the
pipeline from the previous HEAD request (because it doesn't believe there?

> Jun 13 20:37:59 office mount.davfs: Closing connection.
> Jun 13 20:37:59 office mount.davfs: Connection closed.
> Jun 13 20:37:59 office mount.davfs: Request ends, status 0 class 0xx, error line: Could not parse response status line
> Jun 13 20:37:59 office mount.davfs: Running destroy hooks.
> Jun 13 20:37:59 office mount.davfs: Request ends.
>
> Davfs retries every 10 sec, until it works finally, note the timestamp
> shift and the correct status response:

The HEAD request is never going to "work": perhaps at some point davfs
just gives up on the HEAD and does a PUT?

> Jun 13 20:40:43 office mount.davfs: Sending request headers: HEAD /file_store/files/Scanned/test/test12.pdf HTTP/1.1^M Host: 192.168.0.120:9674^M User-Agent: davfs2/1.3.2 neon/0.27.2^M Connection: TE^M TE: trailers^M Authorization: xxxxxxxxxxxxxxxxxx^M ^M
> Jun 13 20:40:43 office mount.davfs: Sending request-line and headers:
> Jun 13 20:40:43 offi...

[Tres Seaver (tseaver)]

One line fix in webdav.NullResource.

[Tres Seaver (tseaver)]

Fix and test for this bug committed on the 2.9 branch:

 http://svn.zope.org/Zope/branches/2.9/?rev=87396&view=rev

the 2.10 branch:

 http://svn.zope.org/Zope/branches/2.10/?rev=87397&view=rev

the 2.11 branch:

 http://svn.zope.org/Zope/branches/2.11/?rev=87398&view=rev

and the trunk:

 http://svn.zope.org/Zope/trunk/?rev=87400&view=rev

[jswinner (jswinner)]

Thanks for the patch

[Tres Seaver (tseaver)]

Included in 2.11.1.