Konstantin Khomoutov
2008-Aug-20 13:29 UTC
Problem with exact moment of issuing transfer log entry for a [recv] action
Some background: I have been assigned a task to implement one-way synchronization of a large file storage to another box. The problem is that on the target box a special directory has to be maintained in which symlinks to received files should be created using special logic. After some experimentation I have set up a named pipe which is used by the receiving rsync daemon for transfer logging; on the reading end of that pipe another daemon sits which reads log entries as the files are being received and creates the necessary symlinks for them. After setting up a test environment I have noticed a problem: some files were linked successfully while some others were not. After studying rsync manuals and its receiver.c more closely it turned out that rsync daemon logs successful "received" event after the file has been received from the wire to a temporary location but has not yet been copied to its target place (I use "rsync -a ..." on the client, so in-place mode is not used). I have created a patch which postpones logging of the "file received" event until after the file has been copied to its target location and so it is really available under the name which is being logged. The patch is attached. I understand that my setup is somewhat unusual and probably could be reimplemented by running a script at the "post-xfer" stage which would consume the transfer log file created by the rsync daemon, process files listed in it and then (re)move the log file. Anyway I think that the solution proposed matches the logging behaviour specified in rsyncd manual more closely; it would be great if someone with sufficient knowledge of rsync internals commented on it. -------------- next part -------------- Postpones logging of successful file transfer up to the moment temporary file was really copied to its target place, not just received. This doesn't change anything for the case when --delay-updates is used, but for this case syncing of external actions on [recv] log entries is explicitly meaningless. --- rsync-3.0.3.orig/receiver.c 2008-08-20 16:28:41.000000000 +0400 +++ rsync-3.0.3/receiver.c 2008-08-20 16:33:06.000000000 +0400 @@ -678,8 +678,6 @@ recv_ok = receive_data(f_in, fnamecmp, fd1, st.st_size, fname, fd2, F_LENGTH(file)); - log_item(log_code, file, &initial_stats, iflags, NULL); - if (fd1 != -1) close(fd1); if (close(fd2) < 0) { @@ -719,6 +717,7 @@ if (remove_source_files || inc_recurse || (preserve_hard_links && F_IS_HLINKED(file))) send_msg_int(MSG_SUCCESS, ndx); + log_item(log_code, file, &initial_stats, iflags, NULL); break; case 0: { enum logcode msgtype = redoing ? FERROR_XFER : FWARNING;