maindavfs2 - Support: sr #107688, incorrect modification times

 
 

sr #107688: incorrect modification times

Submitter:  - <_71007>
Submitted:  Sun 15 May 2011 09:03:18 AM UTC
   
 
Category:  None Priority:  5 - Normal
Severity:  3 - Normal Status:  In Progress
Privacy:  Public Assigned to:  _71007
Open/Closed:  Closed Operating System:  None
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Sat 22 Oct 2011 06:05:33 PM UTC, comment #7: 

If dolphin reports always the same modification time it does not mean that the server works correctly.
From your logs I can see that the server reports different modification times in response to a PROPFIND request than in response to a GEt request. The modification time reported in response to a GET request seems always to be the current time (and not the modification time). This is a server bug.
dophin may only use the time reported in response to PROPATCH. But davfs2 can't do that. When it downloads a file with GET it has to use the modification time it gets from the server together with the file. And if this time is wrong it can't start guessing what might be the correct modification time.

Werner

- <_71007>
Sat 22 Oct 2011 12:28:57 AM UTC, comment #6: 

To test more the behaviour of the server and the davfs2 I logged in through dolphin and repeatedly refreshed the folder. Modification time remains correct at all times.

Jim Geo <jimgeo>
Wed 18 May 2011 07:46:13 PM UTC, comment #5: 

That's what happens:

At the beginning of your logs, file dokimh is in the cache and the stored mtime is 03:52 local time.

On the first ls davfs2 does a PROPFIND request. The response from the server validates what is cached by davfs2. ls shows mtime 03:52 local time.

The first cat (21:04:50 local time) is served by davfs2 from the cache, because the cache has just been validated.

On the next ls davfs2 does another PROPFIND request. The cached data are again validated. mtime is still 03:52.

The next cat is at 21:05:03 local time. Because the last cache validation is more than 1 second in the past davfs2 now does a GET request (it is probably a conditional GET; I'm not sure because there are some lines missing in the log). The server returns the full file contents and it reports 'Last-Modified: Mon, 16 May 2011 18:04:03 GMT' (21:04:03 local time). This clearly says from the server side: the file has been changed. davfs2 correctly replaces the cached file with the new version and updates mtime to what the server says.

The next ls shows this updated mtime. It is what the server reported.

When you unmount and mount again davfs2 still has the latest version and latest information from the server in the cache (mtime 21:04).

Now happens the same as before. As soon as davfs2 does a (conditional) GET request the server reports a new Last-Modified time. davfs2 must act in accordance to the information from the server.

As the file has not been changed on the server this is clearly a server bug. I have never seen this kind of bug from Apache. The bug is most probably in the backend "Servlet 2.5; JBoss-5.0/JBossWeb-2.1". You should file a bug report there.

Cheers
Werner

- <_71007>
Mon 16 May 2011 06:25:16 PM UTC, comment #4: 

here are the logs.

dokimh file modification time on server 16/5/2011 3:31 AM

(file #23411, file #23412)

Jim Geo <jimgeo>
Mon 16 May 2011 06:07:46 PM UTC, comment #3: 

Last time I had the logs and could see what modification time was reported by the server, but I did not know what mtime was reported by davfs2.
Now I have some mtimes reported by davfs2, but don't know what modification time was reported by the server.

The simple question is: when davfs2 reports a different mtime than you expect, where did it get the wrong information from. Was it wrong information from the server or was it an error made by davfs2?

I need both, the output from ls and the logs. And of course the log file must show the same requests as the output from ls.

"Does davfs has a cache for mod times?" But only if a file is in the cache file attributes are cached permanantly and will be restored on the next mount. If a file is not in the cache, file attributes are created from server information and local configuration when the file system is mounted the next time.

"are mod times propagated to the server?" No. Almost no server allows the client to set the modification time.

Cheers
Werner

- <_71007>
Mon 16 May 2011 01:06:47 AM UTC, comment #2: 

I cleared lost+found directory. I unmounted the filesystem.
I mounted it again and created a file.file exists on server.
file modification time is 16/5/2011 3:31 AM in server.
The first time I listed, local mod time was correct.
Then, every time I cat this file time changes (only in local mount).
modification time change is not propagated to the server.
If I unmount and mount again file modification time remains to the new value (web access to the server, file mod time is always 16/5/2011 3:31 AM).

There is a difference between mod time in server and local mount.
Does davfs has a cache for mod times? are mod times propagated to the server?

mount /home/jim/sync
jim@pliroforio ~ $ ls -l /home/jim/sync

-rw-r--r-- 1 jim jim 6 Μάι  16 03:38 dokimh

jim@pliroforio ~ $ cat /home/jim/sync/dokimh
test

jim@pliroforio ~ $ ls -l /home/jim/sync
-rw-r--r-- 1 jim jim 6 Μάι  16 03:43 dokimh

jim@pliroforio ~ $ umount /home/jim/sync
/sbin/umount.davfs: waiting while mount.davfs (pid 27532) synchronizes the cache .. OK

jim@pliroforio ~ $ mount /home/jim/sync
jim@pliroforio ~ $ ls -l /home/jim/sync
-rw-r--r-- 1 jim jim 6 Μάι  16 03:43 dokimh

jim@pliroforio ~ $ cat /home/jim/sync/dokimh
test

jim@pliroforio ~ $ ls -l /home/jim/sync
total 1

-rw-r--r-- 1 jim jim 6 Μάι  16 03:52 dokimh

jim@pliroforio ~ $ umount /home/jim/sync
/sbin/umount.davfs: waiting while mount.davfs (pid 29371) synchronizes the cache .. OK

Jim Geo <jimgeo>
Sun 15 May 2011 09:17:20 AM UTC, comment #1: 

Looking at the debug log you submitted I see:
The file concerned is /webdav/μαθήματα/οπτικάδίκτυα/διαφάνειες/Chapter1.pdf
It is downloaded at Sun, 15 May 2011 00:18:10 GMT (May 15 03:18:10 local time).
The server reports 'Last-Modified: Sun, 15 May 2011 00:17:10 GMT'. This is 03:17:10 local time and looks approximately like 'current time'.

What mtime did ls -l show before and after cat? If it was something else than 03:17:10 before cat, then the file has been changed on the server shortly before the download or the server reported a wrong date in the PROPFIND requests.

There seems to be another problem as well:
Your maximum cache size is set to the default value of 50 MiByte but there are already 55 MiByte cached and davfs2 is not able to remove any of the cached files. Most probably that is due to files in lost+found which davfs2 will never remove automatically. You have to remove them by hand. Files in lost+found usually indicate problems with uploading of files. Are files you create really uploaded to the server?

Cheers
Werner

- <_71007>
Sun 15 May 2011 09:03:18 AM UTC, original submission:  

Jim Geo wrote:
Hello, I have noticed a bug in davfs2 1.4.5 (I don't know if this applies to 1.4.6, in my distro 1.4.5 is stable)
Mount a webdav share, then ls -l in it. Modification times are correct. Then, if a give a "cat myfile" and then execute ls -l, modification time of myfile becomes the current time.
Is there any way to disable or correct this behavior?
I use unison in order to sync my local and server copies and keeping accurate modification times is essential.

Thank you for your time and work.

- <_71007>

 

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

Attach Files:
   
   
Comment:
   

Attached Files
file #23411:  pithoslog2 added by jimgeo (185KiB - application/octet-stream - dokimh file modification time 16/5/2011 3:31 AM)
file #23412:  lsoutpithos added by jimgeo (7KiB - application/octet-stream - dokimh file modification time 16/5/2011 3:31 AM)

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by jimgeo (Posted a comment)
  • -email is unavailable- added by _71007 (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 3 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2012-07-19 _71007 Open/ClosedOpen Closed
    2011-05-16 jimgeo Attached File- Added pithoslog2, #23411
        Attached File- Added lsoutpithos, #23412

    Back to the top

    Powered by Savane 3.13-4b48.
    Corresponding source code