maindavfs2 - Support: sr #107649, Caching and reading partial...

 
 

sr #107649: Caching and reading partial downloads

Submitter:  Joel Ebel <jbebel>
Submitted:  Tue 05 Apr 2011 10:36:36 PM UTC
   
 
Category:  None Priority:  5 - Normal
Severity:  3 - Normal Status:  Postponed
Privacy:  Public Assigned to:  _71007
Open/Closed:  Open Operating System:  GNU/Linux
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Sat 07 May 2011 02:28:43 PM UTC, comment #10: 

Agreed. davfs2 should use ranged requests, at least for GET.
I opened a bug report for this, but without any promise on when I will have time to do something about this.

Werner

- <_71007>
Tue 03 May 2011 09:25:33 PM UTC, comment #9: 

Although, you should consider ranged requests a feature request.  Without that, we will still get timouts on the first download of large files.

Joel Ebel <jbebel>
Mon 02 May 2011 11:00:19 PM UTC, comment #8: 

It turns out the problem is documented and incompatible with our setup:

http://httpd.apache.org/docs/2.2/mod/core.html#fileetag

Our apache servers are load balanced, so we intentionally remove the inode number from the etag, but mod_dav_fs hard codes the etag to INode MTime Size.  Thus the etag for the GET lacks the inode, while the etag from the PROPFIND includes it.  It's too bad the etag for mod_dav_fs isn't configurable.

Feel free to close this request.  It's nothing wrong with davfs, just an unfortunate "feature" of apache.  Thanks for all the help and log studying!

Joel Ebel <jbebel>
Sun 01 May 2011 08:49:50 AM UTC, comment #7: 

davfs2 gets different etags on PROPFIND and GET.

At start davfs2 does a PROPFIND for the root directory:
Request:
line  124: PROPFIND / HTTP/1.1
Response:
line  148: HTTP/1.0 207 Multi-Status
line  561: <D:href>/README</D:href>
line  564: <lp1:getetag>"1694001-3f-4931d671b0000"</lp1:getetag>

The file is not in the davfs2-cache and davfs2 does an unconditional GET:
Request:
line 2646: GET /README HTTP/1.1
Response:
line 2655: HTTP/1.0 200 OK
line 2670: ETag: "3f-4931d671b0000"
The file is cached by davfs2 with etag "3f-4931d671b0000".

The file is in the cache and davfs2 does a conditional GET:
Request:
line 3093: GET /README HTTP/1.1
line 3099: If-None-Match: "3f-4931d671b0000"
Response:
line 3104: HTTP/1.0 304 Not Modified
line 3109: ETag: "3f-4931d671b0000"
davfs2 serves the file system call from its cache as the file is not modified on the server. The file stays in the cache.

In reaction to a ls davfs2 does a PROPFIND:
Request:
line 3509: PROPFIND / HTTP/1.1
Response:
line 3533: HTTP/1.0 207 Multi-Status
line 3947: <D:href>/README</D:href>
line 3950: <lp1:getetag>"1694001-3f-4931d671b0000"</lp1:getetag>
davfs2 will remove the cache file because the etag has changed.

The next GET is again unconditional:
Request:
line 4703: GET /README HTTP/1.1
Response:
line 4713: HTTP/1.0 200 OK
line 4728: ETag: "3f-4931d671b0000"

The reason for removing the cached file is that davfs2 gets etag "3f-4931d671b0000" on GET, but etag "1694001-3f-4931d671b0000" on PROPFIND. What is strange is that the etag in GET is a truncated version of the etag in PROPFIND. The etag in PROPFIND is from the origin server. Maybe the proxy is truncating the etag. But it may be a bug in the origin server as well.

Anyway, etags in PROPFIND and in GET must be identical according to the spec. davfs2 has no workaround to handle mismatching etags as reliable etags are essential in distributed authoring.

I hope the owner of the cache server will be able to locate the bug and to fix it. Maybe the above information will be helpful for this.

Cheers
Werner

- <_71007>
Thu 28 Apr 2011 06:51:12 PM UTC, comment #6: 

The truncated log was my mistake.  I collected the log by grepping for mount.davfs, which the headers didn't contain.  I've attached a new log that includes the headers, as well as the httpbody debug information.  I'll also talk with the owner of the cache server to see why it might be delivering stale data.

(file #23321)

Joel Ebel <jbebel>
Tue 26 Apr 2011 07:32:48 PM UTC, comment #5: 

Thanks for the log file and yes, it looks like a problem with the proxy.

There is a small problem with the log file. The request lines (e.g. line 518: "Sending request headers:" GET and some headers are missing) is truncated. But it is not a big problem. From the context the request method is obvious. I don't know whether this is a problem with davfs2/neon (but I never saw this before) or with the log file.

Now what is going on.

When README is opened the first time davfs2 sends a GET request (line 518). The response is 200 OK meaning the file is fetched from the server. When it is opened for the second time (line 737) the response is 304 Not Modified and davfs2 takes the file from the davfs2 cache. This looks pretty well.

But the response also contains some headers from the proxy that indicate the reason for the trouble:

  • Warning: 110 squid/3.1.11 "Response is stale"
  • Warning: 111 squid/3.1.11 "Revalidation failed"
  • X-Cache: HIT from mirror-cache2-1.mtv.corp.google.com

The proxy served a stale version from its cache because it could not validate it or fetch the latest version from the origin server.

When an ls is done davfs2 will do a PROPFIND request (line 949). The response is 207 Multi-Status which is OK. But the proxy message is now

  • X-Cache: MISS from mirror-cache2-1.mtv.corp.google.com

This response is served from the origin server. The response contains meta-data of the files in the directory, including the etag. Most probably the meta-data from the origin server do not match the ones from the stale response from the proxy and davfs2 removes the stale files from the cache.

To be absolutely sure about this one had to look at the XML-body of the PROPFIND-response which is not included in 'debug most'. You could add option 'debug httpbody' or fetch the http-traffic with Wireshark.

But from all I can see the problem is in that "Revalidation failed"-message. The proxy should not serve stale files.

Cheers
Werner

- <_71007>
Tue 26 Apr 2011 12:11:05 AM UTC, comment #4: 

Attached is a debug=most log of a davfs session.  The following was done:

1.  Mount a filesystem
2.  Cat a README file.
3.  Cat the README file again.  It is not modified, and the cache is used.
4.  ls the directory.  The cache goes away.
5.  Cat the README again.  It is downloaded in full.
6.  Cat README once more, and it comes from the cache.
7.  umount

Is it possible the cache invalidation happens as a result of going through a proxy?  Seems odd that it works until the directory is listed.

(file #23302)

Joel Ebel <jbebel>
Mon 25 Apr 2011 10:05:53 AM UTC, comment #3: 

"Caching:
With some more testing, what seems to be happening is that every file in the cache gets invalidated after dir_refresh seconds. Also, simply running ls, or doing a shell glob of files in a directory invalidates that cache, forcing a full re-download on next read. Is this the expected behavior? I don't understand why reading a directory needs to invalidate the cache of a file in that directory. I could raise the dir_refresh to something ridiculously high, and avoid directory reads, but this would have other consequences as well."
This is not what davfs2 usually does. There is something wrong with cache validation. Maybe the server does not send etags and/or Last_modified headers or changes them without reason.
Running davfs2 with debugging enabled would probably show what is going wrong.

Cheers
Werner

- <_71007>
Wed 20 Apr 2011 09:12:43 PM UTC, comment #2: 

Caching:
With some more testing, what seems to be happening is that every file in the cache gets invalidated after dir_refresh seconds.  Also, simply running ls, or doing a shell glob of files in a directory invalidates that cache, forcing a full re-download on next read.  Is this the expected behavior?  I don't understand why reading a directory needs to invalidate the cache of a file in that directory.  I could raise the dir_refresh to something ridiculously high, and avoid directory reads, but this would have other consequences as well.

Timeouts:
Yes.  The timeouts we are getting are only when the file is not in the cache, but because of the above caching issue, this is frequent.  Unfortunately, the lack of range requests is kind of a blocker for us.  Without it, it seems we'll get frequent timeouts.  We don't want tftp clients to have to retry on a timeout, as many of these requests are done by a BIOS or a network device which have little in the way of configuration to allow this.

For the moment, I'm pursuing fusedav and parrot as alternatives to davfs2, as they seem to handle range requests, and give immediate delivery of files.  They lack caching, but for us, the immediate delivery of available data is far more important.

Joel Ebel <jbebel>
Sun 10 Apr 2011 08:04:57 AM UTC, comment #1: 

Caching:
When a file is requested that is already in the cache davfs2 will do a a conditional GET (header If-Not-Modified) and the file will only be downloaded again when it has changed on the server. Assuming your cache is big enough and the value in option "cache-size" is big enough too. When files are redownloaded without need there is probably something wrong with cache validation. Please set option "debug most" and send the debug messages to see what is going wrong in the communication with the server.

Timeouts:
I assume they occur when the tftp client tries to download a file that is not in the cache. The reason is that davfs2 will first download the complete file before the tftp server can use it. Partial requests (ranged request) would help here but are not implemented in davfs2. AVM's FritzBox uses a patched version of davfs2 that uses ranged requests. But I had not time to look at it more closely and implement it in davfs2.

Better ways to do it:
I am not too familiar with other tools. There are a lot of tools to send and fetch data from a server (scp, rsync, sftp, wget). The problem is to connect these tools with the tftp server.

Cheers
Werner

- <_71007>
Tue 05 Apr 2011 10:36:36 PM UTC, original submission:  

I'm attempting to use davfs2 as a filesystem for serving tftp content, and I'm running into a couple issues.  I'm curious if these features would be possible to implement, or if you have a suggestion for an alternative.

First, the caching doesn't quite work as I expected.  After reading the davfs2.conf man page, I expected that davfs2 would cache files indefinitely, as long as the cache limit was not exceeded, and only re-download if the file had changed on the server.  Would it be possible to implement davfs2 in this manner?  Before re-downloading an expired file in the cache, run a PROPFIND against the file on the server, and not re-download it if it hasn't changed?  This would save a lot of bandwidth, as many of the files we use rarely change.

Secondly, under low bandwidth situations, the tftp clients frequently time out on larger files, and I traced this back to davfs2 not allowing the file to be read as it is being downloaded.  Rather it completely downloads the file, then makes it available for reading.  If the file could be read as it's being downloaded, this would prevent timeouts from the tftp clients waiting for data.

Do you have any better recommendation for getting data on a remote http server served by a local tftp server?  Is davfs2 the wrong tool for the job?

Joel Ebel <jbebel>

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

Attached Files
file #23321:  davfs.http added by jbebel (337KiB - application/octet-stream - davfs log with httpbody)
file #23302:  davfs.log added by jbebel (139KiB - text/x-log - Log of a davfs session)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by _71007 (Posted a comment)
  • -email is unavailable- added by jbebel (Submitted the item)
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only logged-in users can vote.

     

    Follow 5 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2011-05-07 _71007 StatusIn Progress Postponed
    2011-04-28 jbebel Attached File- Added davfs.http, #23321
    2011-04-26 jbebel Attached File- Added davfs.log, #23302
    2011-04-10 _71007 StatusNone In Progress
        Assigned toNone _71007

    Back to the top

    Powered by Savane 3.13-f8d8.
    Corresponding source code