Protocol stream error on extended attribute, silent failure to copy all attributes

Wed Feb 2 04:48:02 MST 2011

> I'm using rsync 3.0.7 on Mac OS X 10.6, compiled according to Mike
> Bombich's instructions at http://www.bombich.com/rsync.html. Rsync
> repeatedly exits with a protocol data stream error when trying to copy
> some com.apple.FinderInfo extended attributes. While testing this issue,
> I found that rsync is not actually copying all extended attributes even
> when there is no error message. I'm using a folder of fonts as an
> example, but I have experienced the protocol error when copying other
> data. This seems like a huge bug, and in my experience those often turn
> out to be operator error. Apologies if I waste anyone's time.
> 
> In this example, I'm using rsync to make a copy from scratch of the
> source data: rsync307 -aX --delete Licensed\ Fonts /Volumes/Storage/
> 
> I repeatedly get this error:
> 
> [sender] internal abbrev error on Licensed Fonts/Postscript/bradley
> (com.apple.FinderInfo, len=32)!
> rsync error: error in rsync protocol data stream (code 12) at
> xattrs.c(636) [sender=3.0.7]
> 
> If you repeat the command a few times, sometimes the error is:
> 
> rsync: writefd_unbuffered failed to write 4 bytes to socket [sender]:
> Broken pipe (32)
> rsync: connection unexpectedly closed (16827 bytes received so far)
> [sender]
> rsync error: error in rsync protocol data stream (code 12) at io.c(601)
> [sender=3.0.7]
> 
> In all my testing, I have only seen the error occur with a
> com.apple.FinderInfo attribute, and only for a directory.
> 
> Running rsync with sudo makes no difference.
> 
> The system has no problem reading the extended attribute from the source
> folder, or using the xattr command to write it to the target folder:
> 
> matt$ xattr -l Licensed\ Fonts/Postscript/bradley/
> com.apple.FinderInfo:
> 00000000  03 99 01 5D 04 7C 02 2F 07 A0 5A 50 00 01 02 07
> |...].|./..ZP....|
> 00000010  FF F8 FF F0 C3 40 00 00 00 00 00 00 00 01 6C 28
> |..... at ........l(|
> 00000020
> matt$ xattr -l /Volumes/Storage/Licensed\ Fonts/Postscript/bradley/
> matt$ xattr -wx com.apple.FinderInfo "`xattr -px com.apple.FinderInfo
> Licensed\ Fonts/Postscript/bradley/`" /Volumes/Storage/Licensed\
> Fonts/Postscript/bradley/
> matt$ xattr -l /Volumes/Storage/Licensed\ Fonts/Postscript/bradley/
> com.apple.FinderInfo:
> 00000000  03 99 01 5D 04 7C 02 2F 07 A0 5A 50 00 01 02 07
> |...].|./..ZP....|
> 00000010  FF F8 FF F0 C3 40 00 00 00 00 00 00 00 01 6C 28
> |..... at ........l(|
> 00000020
> 
> After manually setting the extended attribute, the rsync command
> completes without error messages. The process is repeatable, always
> choking on the bradley folder.
> 
> After rsync completed without error messages, I compared the sizes of
> source and copy:
> 
> matt$ du -k -d1 /Installers/Licensed\ Fonts/
> 245196    /Installers/Licensed Fonts//Adobe Font Folio - OpenType
> Edition
> 51800    /Installers/Licensed Fonts//OpenType
> 256756    /Installers/Licensed Fonts//Postscript
> 43308    /Installers/Licensed Fonts//TrueType
> 598692    /Installers/Licensed Fonts/
> matt$ du -k -d1 /Volumes/Storage/Licensed\ Fonts/
> 245196    /Volumes/Storage/Licensed Fonts//Adobe Font Folio - OpenType
> Edition
> 51800    /Volumes/Storage/Licensed Fonts//OpenType
> 246540    /Volumes/Storage/Licensed Fonts//Postscript
> 38528    /Volumes/Storage/Licensed Fonts//TrueType
> 583696    /Volumes/Storage/Licensed Fonts/
> 
> My understanding is that the sizes should match. The number of items in
> each is the same:
> 
> matt$ du -a /Installers/Licensed\ Fonts/ | wc -l
>   11916
> matt$ du -a /Volumes/Storage/Licensed\ Fonts/ | wc -l
>   11916
> 
> I saved the output of 'du -a' for source and copy, then ran a diff.
> There are hundreds of differences, and it appears that many extended
> attributes were not copied. Here's a typical example:
> 
> matt$ ls -lh Licensed\ Fonts/TrueType/CCZoinks/CCZoinks.t1 
> -rwx------@ 1 matt  matt     0B Jul 16  1999 Licensed
> Fonts/TrueType/CCZoinks/CCZoinks.t1
> matt$ ls -lh Licensed\
> Fonts/TrueType/CCZoinks/CCZoinks.t1/..namedfork/rsrc
> -rwx------  1 matt  matt   9.5K Jul 16  1999 Licensed
> Fonts/TrueType/CCZoinks/CCZoinks.t1/..namedfork/rsrc
> 
> matt$ ls -lh /Volumes/Storage/Licensed\
> Fonts/TrueType/CCZoinks/CCZoinks.t1 
> -rwx------@ 1 matt  matt     0B Jul 16  1999 /Volumes/Storage/Licensed
> Fonts/TrueType/CCZoinks/CCZoinks.t1
> matt$ ls -lh /Volumes/Storage/Licensed\
> Fonts/TrueType/CCZoinks/CCZoinks.t1/..namedfork/rsrc
> -rwx------  1 matt  matt     1B Jul 16  1999 /Volumes/Storage/Licensed
> Fonts/TrueType/CCZoinks/CCZoinks.t1/..namedfork/rsrc
> 
> The file is actually a PostScript Type 1 font, where all the content is
> in the resource fork. Rsync created a com.apple.ResourceFork attribute
> on the new file, but the attribute is empty.
> 
> After this discovery, I ran my original rsync command again, then
> checked sizes:
> 
> matt$ du -kd1 /Volumes/Storage/Licensed\ Fonts/
> 245196    /Volumes/Storage/Licensed Fonts//Adobe Font Folio - OpenType
> Edition
> 51800    /Volumes/Storage/Licensed Fonts//OpenType
> 254488    /Volumes/Storage/Licensed Fonts//Postscript
> 42216    /Volumes/Storage/Licensed Fonts//TrueType
> 595332    /Volumes/Storage/Licensed Fonts/
> 
> More data was copied, but it's still missing things. Overall, it took 6
> runs of the same rsync command to produce a copy that's the same size as
> the original.
> 
> Is this a bug?

Recently, a user posted the following rsync error to the LBackup mailing list : 

> "rsync: writefd_unbuffered failed to write 4 bytes to socket [sender]: Broken pipe (32)
> rsync: connection unexpectedly closed (3225054 bytes received so far) [sender]
> rsync error: error in rsync protocol data stream (code 12) at io.c(601) [sender=3.0.7]"
> 
> Can anyone tell me what it means, why it would occur and most importantly how to fix it.

In their case the destination volume disk was running out of space. However, for some reason rsync was not reporting this error as I would expect. 

A link to this thread on the LBackup mailing is available below :
 http://tinyurl.com/lbackup-discussion-diskfull

I am in the process of attempting to reproduce this error when the disk is full. During testing I have cared out to date, I have not been able to reproduce rsync results error output when the disk is full. In stead I receive something like that which is quoted below.

> rsync: mkstemp 
> "/Volumes/backup_volume/backups/Section.inprogress/to_backup/file_for_which_there_is_not_enough_space.n3pq0e"
>  failed: No space left on device (28)
> rsync_v3.0.7(33235) malloc: *** error for object 0xa: pointer being freed was 
> not allocated
> *** set a breakpoint in malloc_error_break to debug
> rsync: connection unexpectedly closed (22413 bytes received so far) [sender]
> rsync error: error in rsync protocol data stream (code 12) at io.c(601) 
> [sender=3.0.7]

The reason I have replied is because you have the same error reported at the end : 

> rsync error: error in rsync protocol data stream (code 12) at io.c(601)
> [sender=3.0.7]

In addition you are both running on Mac OS X.

If I manage to reproduce this fault then I will report back to this list. In the mean time, perhaps someone with a deeper understanding of these error codes will be able to shed additional light on this error message.

------------------------------------
 This email is protected by LBackup
 http://www.lbackup.org