Problem with exact moment of issuing transfer log entry for a [recv] action

[Konstantin Khomoutov]

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;