rsync - Dec 2005 - WARNING: <file> failed verification -- update discarded (will try again).

I've been using rsync for a long time, and it's very cool.  For the
first time, last night, I got a message I don't understand.  I am using
rsync 2.6.4 on Fedora (FC4) Linux to a Fedora (FC3) Linux machine.  The
command I am using is:

rsync -av --delete-excluded --exclude="*~" --exclude="#*#"
<source dir>
remove_machine:<dest dir>

I got the following as part of the output of rsync:

jukebox/Frank_Sinatra/
jukebox/Frank_Sinatra/The_Main_Event/
jukebox/Frank_Sinatra/The_Main_Event/01-Tribute.flac
jukebox/Frank_Sinatra/The_Main_Event/02-The_Lady_Is_A_Tramp.flac
jukebox/Frank_Sinatra/The_Main_Event/03-I_Get_A_Kick_Out_Of_You.flac
jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
jukebox/Frank_Sinatra/The_Main_Event/05-Autumn_In_New_York.flac
jukebox/Frank_Sinatra/The_Main_Event/06-Ive_Got_You_Under_My_Skin.flac
jukebox/Frank_Sinatra/The_Main_Event/07-Bad_Bad_Leroy_Brown.flac
jukebox/Frank_Sinatra/The_Main_Event/08-Angel_Eyes.flac
jukebox/Frank_Sinatra/The_Main_Event/09-You_Are_The_Sunshine_Of_My_Life.flac
jukebox/Frank_Sinatra/The_Main_Event/10-The_House_I_Live_In.flac
jukebox/Frank_Sinatra/The_Main_Event/11-My_Kind_Of_Town.flac
WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
failed verification -- update discarded (will try again).
jukebox/Frank_Sinatra/The_Main_Event/12-My_Way.flac

What does the "WARNING" imply?  What could have gone wrong?  I cannot
reproduce it.  When I did another sync immediately after, only the
directory was in the file list, and then I checked the file in question,
and it matched the source.

I saw mention of a similar error in an older version when using "-z",
but I am not using that.

					Thanks, Joe

On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson
wrote:
> WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
> failed verification -- update discarded (will try again).
> 
> What does the "WARNING" imply?  What could have gone wrong?  I
cannot
> reproduce it.  When I did another sync immediately after, only the
> directory was in the file list, and then I checked the file in question,
> and it matched the source.
If I saw that, the first thing I'd do is fsck.  If fsck found/fixed
errors, I wouldn't give it another thought.  If not, I'd think harder
while trying to remember where I left my gamma-ray shield.  :)

-chris

Hey, I always have my gamma-ray shield with me!  :)

But seriously, are you saying this indicates a read or write error?
I''ve googled for other cases of this, and when there was an error (like
an error reading a mounted partition), the error was reported before the
warning.  In my case, no other messages are seen other than that warning.

					-Joe


Chris Shoemaker wrote:
> On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson wrote:
> 
>>WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
>>failed verification -- update discarded (will try again).
>>
>>What does the "WARNING" imply?  What could have gone wrong?  I
cannot
>>reproduce it.  When I did another sync immediately after, only the
>>directory was in the file list, and then I checked the file in question,
>>and it matched the source.
> 
> 
> If I saw that, the first thing I''d do is fsck.  If fsck
found/fixed
> errors, I wouldn''t give it another thought.  If not, I''d
think harder
> while trying to remember where I left my gamma-ray shield.  :)
> 
> -chris
>

On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson
wrote:
> WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
> failed verification -- update discarded (will try again).
> jukebox/Frank_Sinatra/The_Main_Event/12-My_Way.flac
> 
> What does the "WARNING" imply?
It is telling you that the updated file that rsync created didn''t match
the checksum that the sender told us.  There are a number of different
ways this can happen (all of them pretty rare, but not impossible):

If this was an update (not a newly-created file):

    - A block checksum may have gotten a match on some local data that
      wasn''t really identical, so the constructed file wasn''t
correct.
      (The redo-pass uses a slightly different block size in order to
      work-around such a rare occurrence.)

    - If someone was modifying the file on the receiving side during the
      interval between rsync generating the checksum data and the local
      data being used to recreate the updated file, that can also cause
      the end result to be incorrect (due to different data being copied
      from what rsync was expecting).

For both updates and new files:

    - If the sender got a read-error reading the file, the checksum is
      forced to be invalid because this is the only current way rsync
      has to tell the receiving side to discard the updated file.
      (The observed behavior is not consistent with this possibility,
      so you can ignore this one.)

    - If the data being sent over the socket was corrupted (somehow), it
      may be that the corruption to occurred inside the file data.  This
      is usually only possible with failing hardware, buggy networking
      drivers, and things like that.

..wayne..

Wayne Davison wrote:
> It is telling you that the updated file that rsync created didn''t
match
> the checksum that the sender told us.  There are a number of different
> ways this can happen (all of them pretty rare, but not impossible):
Thanks for clearing this up!
>     - A block checksum may have gotten a match on some local data that
>       wasn''t really identical, so the constructed file
wasn''t correct.
>       (The redo-pass uses a slightly different block size in order to
>       work-around such a rare occurrence.)
I wonder if this could be it.  The file in question may mainly differ,
overall, from the original file as an offset of bytes, since it is
compressed audio that was shifted by only 120 samples in the new
version.  I wonder if that "subtle" change could increase the
probability of block checksums matching.
>     - If someone was modifying the file on the receiving side during the
>       interval between rsync generating the checksum data and the local
>       data being used to recreate the updated file, that can also cause
>       the end result to be incorrect (due to different data being copied
>       from what rsync was expecting).
Not the case here.
>     - If the data being sent over the socket was corrupted (somehow), it
>       may be that the corruption to occurred inside the file data.  This
>       is usually only possible with failing hardware, buggy networking
>       drivers, and things like that.
Hmm, hope not.  It''s on a directly attached ethernet with HW
that''s been
stable over time with ECC memory, etc.  But who knows.  This is
certainly a scary possibility.  I checked the SMART logs on my hard
drives and they show no issue, so that''s good.  The ethernet
connection,
unless, as you say, there were a driver issue, should be TCP protected
(I am not specifying "-e", but it appears rsync chooses ssh as the
method by default).

I suppose I could have tripped upon an very obscure bug, but that''s
probably unlikely (and yet most people would never catch the warning if
it had scrolled off their screen, so who knows how common it is).

						-Joe

On Wed, 2005-12-07 at 13:50 -0500, Chris Shoemaker
wrote:
> On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson wrote:
> > WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
> > failed verification -- update discarded (will try again).
> > 
> > What does the "WARNING" imply?  What could have gone wrong? 
I cannot
> > reproduce it.  When I did another sync immediately after, only the
> > directory was in the file list, and then I checked the file in
question,
> > and it matched the source.
> 
Perhaps rsync can interpret filenames as instructions?!  :-)

:)  Yeah, I noticed that too!  A little too coincidental for comfort!


Mike Daws wrote:
> On Wed, 2005-12-07 at 13:50 -0500, Chris Shoemaker wrote:
> 
>>On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson wrote:
>>
>>>WARNING:
jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
>>>failed verification -- update discarded (will try again).
>>>
>>>What does the "WARNING" imply?  What could have gone
wrong?  I cannot
>>>reproduce it.  When I did another sync immediately after, only the
>>>directory was in the file list, and then I checked the file in
question,
>>>and it matched the source.
>>
> Perhaps rsync can interpret filenames as instructions?!  :-)
>

Wayne,

I just did some more testing to see if I could reproduce the warning,
and I was successful.  I tried manually setting "--checksum-seed"
equal
to timestamps around the time of the error, and I hit a case pretty
quickly on that same file.  It reproduces over and over, so it''s
definitely the first cause you list below or some other deterministic
rsync thing.

Now that I have a test case, would be it worth investigating?  You said
it should be rare, so I wonder if something else could be afoot and
therefore worth checking.

Anyway, here is the output:

----------- Checksum seed: 1133910002
building file list ... done
04-Let_Me_Try_Again.flac
WARNING: 04-Let_Me_Try_Again.flac failed verification -- update
discarded (will try again).
04-Let_Me_Try_Again.flac

(command is: rsync -av --checksum-seed=1133910002 --delete-excluded
--exclude="*~" --exclude="#*#"
new/The_Main_Event/04-Let_Me_Try_Again.flac host:/tmp)

Let me know if I can help to track this down, or I could send you the
files (new and old) in question.

					Thanks, Joe

Wayne Davison wrote:
> On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson wrote:
> 
>>WARNING: jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
>>failed verification -- update discarded (will try again).
>>jukebox/Frank_Sinatra/The_Main_Event/12-My_Way.flac
>>
>>What does the "WARNING" imply?
> 
> 
> It is telling you that the updated file that rsync created didn''t
match
> the checksum that the sender told us.  There are a number of different
> ways this can happen (all of them pretty rare, but not impossible):
> 
> If this was an update (not a newly-created file):
> 
>     - A block checksum may have gotten a match on some local data that
>       wasn''t really identical, so the constructed file
wasn''t correct.
>       (The redo-pass uses a slightly different block size in order to
>       work-around such a rare occurrence.)
> 
>     - If someone was modifying the file on the receiving side during the
>       interval between rsync generating the checksum data and the local
>       data being used to recreate the updated file, that can also cause
>       the end result to be incorrect (due to different data being copied
>       from what rsync was expecting).
> 
> For both updates and new files:
> 
>     - If the sender got a read-error reading the file, the checksum is
>       forced to be invalid because this is the only current way rsync
>       has to tell the receiving side to discard the updated file.
>       (The observed behavior is not consistent with this possibility,
>       so you can ignore this one.)
> 
>     - If the data being sent over the socket was corrupted (somehow), it
>       may be that the corruption to occurred inside the file data.  This
>       is usually only possible with failing hardware, buggy networking
>       drivers, and things like that.
> 
> ..wayne..
>

BTW, my test case is a sending rsync version 2.6.4-3 (Fedora FC4) and a
receiving rsync 2.6.3-1 (Fedora FC3).

Within a range of 25 or so minutes of --checksum-seed values (unix time
stamps), I see the warning for 3 times.

	-Joe


Joe Peterson wrote:
> Wayne,
> 
> I just did some more testing to see if I could reproduce the warning,
> and I was successful.  I tried manually setting "--checksum-seed"
equal
> to timestamps around the time of the error, and I hit a case pretty
> quickly on that same file.  It reproduces over and over, so it''s
> definitely the first cause you list below or some other deterministic
> rsync thing.
> 
> Now that I have a test case, would be it worth investigating?  You said
> it should be rare, so I wonder if something else could be afoot and
> therefore worth checking.
> 
> Anyway, here is the output:
> 
> ----------- Checksum seed: 1133910002
> building file list ... done
> 04-Let_Me_Try_Again.flac
> WARNING: 04-Let_Me_Try_Again.flac failed verification -- update
> discarded (will try again).
> 04-Let_Me_Try_Again.flac
> 
> (command is: rsync -av --checksum-seed=1133910002 --delete-excluded
> --exclude="*~" --exclude="#*#"
> new/The_Main_Event/04-Let_Me_Try_Again.flac host:/tmp)
> 
> Let me know if I can help to track this down, or I could send you the
> files (new and old) in question.
> 
> 					Thanks, Joe
> 
> Wayne Davison wrote:
> 
>>On Wed, Dec 07, 2005 at 11:38:25AM -0700, Joe Peterson wrote:
>>
>>
>>>WARNING:
jukebox/Frank_Sinatra/The_Main_Event/04-Let_Me_Try_Again.flac
>>>failed verification -- update discarded (will try again).
>>>jukebox/Frank_Sinatra/The_Main_Event/12-My_Way.flac
>>>
>>>What does the "WARNING" imply?
>>
>>
>>It is telling you that the updated file that rsync created
didn''t match
>>the checksum that the sender told us.  There are a number of different
>>ways this can happen (all of them pretty rare, but not impossible):
>>
>>If this was an update (not a newly-created file):
>>
>>    - A block checksum may have gotten a match on some local data that
>>      wasn''t really identical, so the constructed file
wasn''t correct.
>>      (The redo-pass uses a slightly different block size in order to
>>      work-around such a rare occurrence.)
>>
>>    - If someone was modifying the file on the receiving side during the
>>      interval between rsync generating the checksum data and the local
>>      data being used to recreate the updated file, that can also cause
>>      the end result to be incorrect (due to different data being copied
>>      from what rsync was expecting).
>>
>>For both updates and new files:
>>
>>    - If the sender got a read-error reading the file, the checksum is
>>      forced to be invalid because this is the only current way rsync
>>      has to tell the receiving side to discard the updated file.
>>      (The observed behavior is not consistent with this possibility,
>>      so you can ignore this one.)
>>
>>    - If the data being sent over the socket was corrupted (somehow), it
>>      may be that the corruption to occurred inside the file data.  This
>>      is usually only possible with failing hardware, buggy networking
>>      drivers, and things like that.
>>
>>..wayne..
>>
> 
>