maindavfs2 - Support: sr #108998, Rsync produces 0KB files

 
 

sr #108998: Rsync produces 0KB files

Submitter:  kpg <gkovacsp>
Submitted:  Sun 20 Mar 2016 09:48:32 AM UTC
   
 
Category:  None Priority:  5 - Normal
Severity:  3 - Normal Status:  Done
Privacy:  Public Assigned to:  _71007
Open/Closed:  Closed Operating System:  GNU/Linux
* Mandatory Fields

Add a New Comment Rich Markup
   

Jump to the original submission

Mon 28 Mar 2016 06:52:36 PM UTC, comment #8: 

Thanks for the elaborate answer, inplace will be my way to go!

kpg <gkovacsp>
Mon 28 Mar 2016 02:32:40 PM UTC, comment #7: 

Thanks for the log file. I could see the most probable error from them. Fortunately I have a test account on box.com too. With same small additional tests I am now sure to know what is going wrong and how to avoid this.

What happens
============

When rsync runs without option "--inplace" and tries to update a remote file, it will first create a temporary file e.g. /dav/images/.00000001.png.ngYvup. After this file is complete and closed it will rename it to the final name /dav/images/00000001.png. With a davfs2 file system and the box.com server this is what happens:

  • rsync opens the new file /dav/images/.00000001.png.ngYvup. davfs2 will create an empty file for this in its cache and lock that file on the server (locking on the server is done to avoid clashes with some other client that has access to the same WebDAV-repository). box.com creates a new empty file, locks it and sends back a lock-token (davfs2 will need this for further write access to that file on the server).


  • rsync writes data to the file and closes the file. davfs2 writes this data to the file in the local cache and closes this cache file.


  • rsync renames the file into /dav/images/00000001.png. To do this renaming on the server davfs2 uses the WebDAV HTTP method MOVE and box.com renames the file accordingly.


  • This is the point where things go wrong. The source of the MOVE operation (the temporary file) is locked on the server. According to the WebDAV RFC this lock must not be moved to the destination. So /dav/images/00000001.png has to be unlocked, but box.com locks the file. Because the file should be unlocked and davfs2 has still to write data to this file, davfs2 tries to lock the file. It gets an error code (423 Locked) from the server. davfs2 now tries to get the lock-token from server. This is an optional feature in WebDAV and box.com does not support it.


  • When davfs2 some seconds later tries to use the PUT-request to send the data to file /dav/images/00000001.png on the server this request fails because davfs2 does not know the lock-token. davfs2 moves the file into directory lost+found. This entry in lost+found points to the file in the local cache.


How to avoid this problem
=========================

Running rsync with option --inplace is indeed the best way to avoid this. In this case rsync will not create a temporary file and the renaming and the MOVE-request are avoided. It is a good idea to use this option anyway because with a davfs2 file system the temporary file does not increase security but only introduces unnecessary complexity.

Another way would be to disable locking. WebDAV locks are only useful when there is concurrent access to the WebDAV repository from different clients. So if you are sure that your davfs2 file system is the only client that has access to your WebDAV repository at that time, you should add option "use_locks 0" to your davfs2.conf file (in addition to the option --inplace for rsync).

Additional Information
======================

I did some additional tests with different servers. Instead of using rsync I used some simple commands. First I created file test and made sure it was uploaded to the server. Then I issued this command
  echo "new content" > test.xyz; mv test.xyz test
This gives the same sequence of HTTP requests.

Results:

box.com with locks enabled: fails as expected.

box.com with locks disabled: no error.

sd2dav.1und1.de (WebDAV server of my ISP) with locks enabled: no error.

public.bscw.de (a collaboration software developed by Fraunhofer Institut) with locks enabled: like box.com the destination file of MOVE is locked when the source is locked, but different from box.com it allows davfs2 to get the lock-token, so it works.

The relevant part of the WebDAV RFC is: RFC 4918, 7.6   Write Locks and COPY/MOVE.

Cheers
Werner

P.S.: When you mount your davfs2 file system you will probably find a lot of files in the lost+found directory (from failed runs of rsync). You can safely remove them. They will then also be removed from the cache.

- <_71007>
Sun 27 Mar 2016 12:47:55 PM UTC, comment #6: 

I've had problems with the initial uploads, so I debugged the system while trying to sync four files up to box.com.

The files are:
-00000001.png
-00000002.png
-AustrĂ¡lia.part1.rar
-AustrĂ¡lia.part2.rar

I used the following command line:
sudo rsync -au /home/pi/davfs2-test-folder/ /mnt/box.com/kpgd@jogasziget.hu

After unmount the box.com web interface shows the files as 0KB
https://www.dropbox.com/s/u121rner2sk2trv/box.com.0kb.png?dl=1

If I use a simple cp command  (or Midnight Commander) to copy these files, then they are correctly uploaded.

The davfs2 cache folder contains the following after unmount:
https://www.dropbox.com/s/vzmwdwopnfny5uc/davfs2-cace.png?dl=1

Syslog is available from here: https://www.dropbox.com/s/sxwhkq78wv1t8y4/syslog?dl=1

I hope it helps. For me the --inplace workaround is perfect.

As I've mentioned before, rsync has been working for many years without inplace, I use it for regular backups.

kpg <gkovacsp>
Sun 27 Mar 2016 07:57:09 AM UTC, comment #5: 

What I forgott:
After you have finished the test you should remove option "debug most" to keep your log files from exploding.

- <_71007>
Sun 27 Mar 2016 07:55:35 AM UTC, comment #4: 

To keep the debug logs from getting to big the directory you are synchronizing should be small. If your directory has only 10 or 20 files then it is ok. Otherwise

  • create a small local test directory (only a few files)


  • copy this directory into your davfs2 file system and unmount the file system


  • check that everything is on the server


Now we can start debugging:

  • while the file system is not mountet add option "debug most" to your davfs2.conf file


  • change one single file in your local test directory


  • mount the davfs2 file system


  • run rsync on your test directory without option --inplace


  • unmount the file system


  • search your log files for messages from mount.davfs (/var/log/syslog or debug or daemon.log, depending on your system)


  • check whether the error happend again


  • send the debug messages as file attechment to this list (there shouldn't be confidential informations in the debug messages, but please check before sending)


I will try to analize the messages to find out what is going wrong.

Cheers
Werner

- <_71007>
Sat 26 Mar 2016 07:51:01 PM UTC, comment #3: 

Thanks for the answer.
 
If you send me the instructions I'll run the test for you.

I use only the --size-only option in rsync, so file dates should not cause problems.

kpg <gkovacsp>
Sat 26 Mar 2016 07:46:49 PM UTC, comment #2: 

I just intended to answer your request when I noticed your second message. So it seems to work now.

If you are interested to find out what is the reason for this behaviour, this would need some work:
- set up a small test directory to use with rsync (small to keep the amount of debug messages small)
- enable some debug options
- find the messages in the log files and analyse them.

I would be interested in doing this. If you want to do it too, please tell me, so I can give you detailed instructions.

One remark an using rsync with davfs2:
When the file system is mounted, davfs2 maintains local file times to avoid confusing applications. But the LastModified time on the server will be different (some 10 seconds later). When you unmount the file system only the local attributes of those files will be preserved, that are in the cache directory. When you mount again all other files will get the LastModified time from the server as mtime. rsync will probably use this time to decide whether a file has changed. So you should not change files in your local directory, before the davfs2 file system is unmounted and all files are uploaded to the server.

Werner

- <_71007>
Sat 26 Mar 2016 07:08:21 PM UTC, comment #1: 

It seems adding --inplace to the rsync options solves the problem.

It was not necessary earlier, so something has changed somewhere. I don't know if it was:

-rsync
-box.com
-davfs2

kpg <gkovacsp>
Sun 20 Mar 2016 09:48:32 AM UTC, original submission:  

I use davfs2 together with rsync to backup photos to box.com on a raspberry pi/raspbian.

Rsync seems to run properly, it displays the uploading progress bars, but when the process completes I see only 0KB files on box.com.

If I just copy files to the davfs2 mount (using midnight commander), then they are uploaded properly.

Apart from the

cache_size        1000              # MiByte

all the other config parameters are left intact

my rsync command

> rsync -avu --max-size=245MB --delete --update --size-only --progress LOCALPATGH REMOTEPATH


After rsync completes all the "should be uploaded" files are listed in the /var/cache/davfs2 directory, but they never get uploaded

kpg <gkovacsp>

 

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

Attach Files:
   
   
Comment:
   

No files currently attached

 

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 gkovacsp (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 4 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2019-12-26 _71007 Open/ClosedOpen Closed
    2016-03-28 _71007 StatusIn Progress Done
    2016-03-26 _71007 StatusNone In Progress
        Assigned toNone _71007

    Back to the top

    Powered by Savane 3.13-4448.
    Corresponding source code