strange log values in 3.1

[Carlos Carvalho-3]

I've just got the log lines below. The first line shows the format
spec that prints each column:

   %'b          %'l       %f
0              18,760     f1
0              11,193     f2
32,768         2,186      f3
3,128,368      3,453,856  f4
13,680         11,786     f5
32,768         6,288      f6
0              6,498      f7
0              6,346      f8
0              6,570      f9
32,768         18,010     f10
0              6,282      f11
0              6,386      f12
0              872        f13
32,768         43,395     f14
15,440         9,920      f15
0              4,575      f16
11,584         1,435      f17
41,992         51,326     f18
49,232         49,918     f19
10,778         4,545      f20
0              1,078      f21
384,526        389,645    f22

All files are new. What I find strange is that I'd expect the
transfered bytes to be somewhat larger than the file sizes, like in f4
and f22 above. However there's sometimes a big difference, with the
net transfer being much larger. See for example f3, f6, f15. On the
other hand, sometimes the first column is noticeably smaller, for
example f18. The files are all new, not updated. They were pulled
almost in the sequence above, I just removed some dir entries in the
middle.

Are the logged %b entries being used by parts of different files,
particularly for the small ones? I've never noticed this with earlier
versions and since the apostrophes are a new feature I'm reporting it,
just in case.
--
Please use reply-all for most replies to avoid omitting the mailing list.
To unsubscribe or change options: https://lists.samba.org/mailman/listinfo/rsync
Before posting, read: http://www.catb.org/~esr/faqs/smart-questions.html

[Wayne Davison-2]

On Sun, Oct 25, 2009 at 6:26 PM, Carlos Carvalho <carlos@...> wrote:

All files are new. What I find strange is that I'd expect the transfered bytes to be somewhat larger than the file sizes

Yeah, there are two problems.  One was that the %b modifier requires late-logging (after the transfer finishes), and the log-format scanner hadn't been updated to understand apostrophes, so it wouldn't find %'b.  If nothing else triggered the after-the transfer output, you would have seen some constant value (like 0) for every file.  The second issue is the reason you saw several files at 0 followed by some too-big numbers: the %b and %c routines are outputting differences in stats read/written values, and the newest I/O code counts these bytes as they are read/written from/to the socket, so the buffering gets in the way of the per-files stats.

I've checked in a fix for the apostrophe issue, and am working up a fix for the per-transfer stats.  Thanks for the report!

..wayne..

--
Please use reply-all for most replies to avoid omitting the mailing list.
To unsubscribe or change options: https://lists.samba.org/mailman/listinfo/rsync
Before posting, read: http://www.catb.org/~esr/faqs/smart-questions.html

[Carlos Carvalho-3]

Wayne Davison (wayned@...) wrote on 25 October 2009 22:33:
 >On Sun, Oct 25, 2009 at 6:26 PM, Carlos Carvalho <carlos@...>wrote:
 >
 >> All files are new. What I find strange is that I'd expect the transfered
 >> bytes to be somewhat larger than the file sizes
 >>
 >
 >Yeah, there are two problems.  One was that the %b modifier requires
 >late-logging (after the transfer finishes), and the log-format scanner
 >hadn't been updated to understand apostrophes, so it wouldn't find %'b.  If
 >nothing else triggered the after-the transfer output, you would have seen
 >some constant value (like 0) for every file.  The second issue is the reason
 >you saw several files at 0 followed by some too-big numbers: the %b and %c
 >routines are outputting differences in stats read/written values, and the
 >newest I/O code counts these bytes as they are read/written from/to the
 >socket, so the buffering gets in the way of the per-files stats.
 >
 >I've checked in a fix for the apostrophe issue, and am working up a fix for
 >the per-transfer stats.  Thanks for the report!

I've applied your last two patches by hand (the nightly wasn't updated
until Ter Out 27 01:57:09 UTC 2009?!). It "looks" better, such as
there are no more zeros in the %b column. However I'm not sure it's
completely fixed. Here are some suspicious entries:

%-14'b         %-14'l
4,736          75,684   name
32,420         417,216  other name

Both are for new files, so I wonder how rsync can guess so much about
them without coming from the net.

Also, summing all entries in the second column I get 386.24MB (not
MiB). However rsync says "Total transferred file size: 367.43M bytes"
using -hh. The difference seems too large.

Just remembered I had --fuzzy in the config. Could it be the cause? It
wouldn't explain the difference of the previous paragraph though.
--
Please use reply-all for most replies to avoid omitting the mailing list.
To unsubscribe or change options: https://lists.samba.org/mailman/listinfo/rsync
Before posting, read: http://www.catb.org/~esr/faqs/smart-questions.html