Problem with rsync recent file logic ?

[Maxim Veksler]

Hello,

I have 2 servers I'm synchronizing using rsync, I have a situation where I :

1. rsync from rnd-dev2 to rnd-dev1
2. change the rsynched file on rnd-dev1
3. rsync from rnd-dev2 to rnd-dev1 again
4. File gets overridden on rnd-dev1 over though it has newer change
time then file on rnd-dev2.


here is the bug(?) reproduction:

[root at rnd-dev1 test_rsync]# rsync --version
rsync  version 2.6.3  protocol version 28
Copyright (C) 1996-2004 by Andrew Tridgell and others
<http://rsync.samba.org/>
Capabilities: 64-bit files, socketpairs, hard links, symlinks, batchfiles,
              inplace, IPv6, 64-bit system inums, 64-bit internal inums


[root at rnd-dev1 maxim]# mkdir /tmp/test_rsync
[root at rnd-dev2 maxim]# mkdir /tmp/test_rsync

[root at rnd-dev2 test_rsync]# dd if=/dev/urandom of=maxim_file.dat count=1024
[root at rnd-dev2 test_rsync]# md5sum maxim_file.dat
517cbaefb385f64823179b253844fff0  maxim_file.dat
[root at rnd-dev2 test_rsync]# stat maxim_file.dat
  File: `maxim_file.dat'
  Size: 524288          Blocks: 1032       IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 1081370     Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2007-11-15 12:25:30.000000000 +0200
Modify: 2007-11-15 12:24:37.000000000 +0200
Change: 2007-11-15 12:24:37.000000000 +0200

[root at rnd-dev2 test_rsync]# rsync --timeout 20 -avvr /tmp/test_rsync/
-e ssh root at rnd-dev1:/tmp/test_rsync/
opening connection using ssh -l root rnd-dev1 rsync --server
-vvlogDtpr --timeout=20 . /tmp/test_rsync/
building file list ...
[sender] expand file_list to 131072 bytes, did move
done
delta transmission enabled
./
maxim_file.dat
total: matches=0  tag_hits=0  false_alarms=0 data=524288

sent 524456 bytes  received 40 bytes  1048992.00 bytes/sec
total size is 524288  speedup is 1.00

[root at rnd-dev2 test_rsync]# md5sum maxim_file.dat
517cbaefb385f64823179b253844fff0  maxim_file.dat
[root at rnd-dev1 test_rsync]# md5sum maxim_file.dat
517cbaefb385f64823179b253844fff0  maxim_file.dat

######### So far so good ## Here comes the BUG part ######

[root at rnd-dev1 test_rsync]# dd if=/dev/urandom of=maxim_file.dat count=1024
1024+0 records in
1024+0 records out
[root at rnd-dev1 test_rsync]# md5sum maxim_file.dat
c780e88b1bf60e5cb31ead145c5c3b39  maxim_file.dat
[root at rnd-dev1 test_rsync]# stat maxim_file.dat
  File: `maxim_file.dat'
  Size: 524288          Blocks: 1032       IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 261636      Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2007-11-15 12:33:32.000000000 +0200
Modify: 2007-11-15 12:33:37.000000000 +0200
Change: 2007-11-15 12:33:37.000000000 +0200

root at rnd-dev2 test_rsync]# stat maxim_file.dat
  File: `maxim_file.dat'
  Size: 524288          Blocks: 1032       IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 1081370     Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2007-11-15 12:35:06.000000000 +0200
Modify: 2007-11-15 12:24:37.000000000 +0200
Change: 2007-11-15 12:24:37.000000000 +0200


[root at rnd-dev2 test_rsync]# rsync --timeout 20 -avvvr /tmp/test_rsync/
-e ssh root at rnd-dev1:/tmp/test_rsync/
opening connection using ssh -l root rnd-dev1 rsync --server
-vvvlogDtpr --timeout=20 . /tmp/test_rsync/
building file list ...
[sender] make_file(.,*,2)
[sender] expand file_list to 131072 bytes, did move
[sender] make_file(maxim_file.dat,*,2)
[sender] popping per-dir .cvsignore exclude list
done
send_file_list done
send_files starting
server_recv(2) starting pid=12320
recv_file_name(.)
recv_file_name(maxim_file.dat)
received 2 names
recv_file_list done
get_local_name count=2 /tmp/test_rsync/
recv_files(2) starting
generator starting pid=12320 count=2
delta transmission enabled
recv_generator(.,0)
recv_generator(maxim_file.dat,1)
generating and sending sums for 1
send_files(1, /tmp/test_rsync/maxim_file.dat)
count=729 rem=128 blength=720 s2length=2 flength=524288
send_files mapped /tmp/test_rsync/maxim_file.dat of size 524288
calling match_sums /tmp/test_rsync/maxim_file.dat
maxim_file.dat
built hash table
hash search b=720 len=524288
done hash search
sending file_sum
false_alarms=0 tag_hits=5722 matches=0
sender finished /tmp/test_rsync/maxim_file.dat
generate_files phase=1
send_files phase=1
recv_files(maxim_file.dat)
recv mapped maxim_file.dat of size 524288
got file_sum
set modtime of .maxim_file.dat.HiyTJQ to (1195122277) Thu Nov 15 12:24:37 2007
renaming .maxim_file.dat.HiyTJQ to maxim_file.dat
recv_files phase=1
generate_files phase=2
send files finished
total: matches=0  tag_hits=5722  false_alarms=0 data=524288
recv_generator(.,0)
set modtime of . to (1195122277) Thu Nov 15 12:24:37 2007
generate_files finished
recv_files finished

sent 524456 bytes  received 4414 bytes  352580.00 bytes/sec
total size is 524288  speedup is 0.99
_exit_cleanup(code=0, file=main.c, line=702): about to call exit(0)

[root at rnd-dev1 test_rsync]# stat maxim_file.dat
  File: `maxim_file.dat'
  Size: 524288          Blocks: 1032       IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 261636      Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2007-11-15 12:35:05.000000000 +0200
Modify: 2007-11-15 12:24:37.000000000 +0200
Change: 2007-11-15 12:35:05.000000000 +0200

[root at rnd-dev2 test_rsync]# stat maxim_file.dat
  File: `maxim_file.dat'
  Size: 524288          Blocks: 1032       IO Block: 4096   regular file
Device: fd00h/64768d    Inode: 1081370     Links: 1
Access: (0644/-rw-r--r--)  Uid: (    0/    root)   Gid: (    0/    root)
Access: 2007-11-15 12:35:06.000000000 +0200
Modify: 2007-11-15 12:24:37.000000000 +0200
Change: 2007-11-15 12:24:37.000000000 +0200

[root at rnd-dev1 test_rsync]# md5sum maxim_file.dat
517cbaefb385f64823179b253844fff0  maxim_file.dat

#### Note that file got rsynced from rnd-dev2 and had it's change date
updated to older time (of rnd-dev2). As well as the content that got
replaced by the out dated version on rnd-dev2. Bummer...


What am I missing to get it do the right thing? I would expect rsync
when called the second time from rnd-dev2 to recognize that the file
on rnd-dev1 is newer and to NOT replaced it.


Thank you,
Maxim.

-- 
Cheers,
Maxim Veksler

"Free as in Freedom" - Do u GNU ?