rsync - Mar 2005 - wierd duration shown in progress with 0 byte files

While trying out the 2.6.4-pre2, I noticed something wierd with
--progress; it shows:

ads/promotions.MYD
           0 100%    0.00kB/s  519:35:46  (61, 56.3% of 597)

This is quite reproducable whenever an empty file is transferred (or
created on the receiving end).

Commandline used was:

rsync -zave 'ssh -c arcfour' --progress --stats --delete
lisa:/var/lib/mysql/ .

BTW, this also happened with 2.6.0 which was first installed on these
systems.

I looked into progress.c, but beyond eliminating some redundant code :-)
I couldn't fix it quickly. It looks like something isn't being
initialised: the duration shown is always the same during one run; when
removing these empty files and doing a new run, they all show the same
large value, which will be different from the previous run.

This is my little improvement (I hope) on progress.c:

--- progress.c.orig	2005-03-04 22:58:39.000000000 +0100
+++ progress.c	2005-03-04 23:07:13.000000000 +0100
@@ -68,9 +68,8 @@
 	if (is_last) {
 		/* Compute stats based on the starting info. */
 		diff = msdiff(&ph_start.time, now);
-		if (!diff)
-			diff = 1;
-		rate = (double) (ofs - ph_start.ofs) * 1000.0 / diff / 1024.0;
+		rate = diff ? (double) (ofs - ph_start.ofs) * 1000.0
+		    / diff / 1024.0 : 0;
 		/* Switch to total time taken for our last update. */
 		remain = (double) diff / 1000.0;
 	} else {

I don't quite see the point of setting diff to 1ms if it's zero...
Better to use the same logic as the other branch of the if statement
takes.


Paul Slootman

On Fri, Mar 04, 2005 at 11:13:22PM +0100, Paul Slootman
wrote:
>            0 100%    0.00kB/s  519:35:46  (61, 56.3% of 597)
> 
> This is quite reproducable whenever an empty file is transferred (or
> created on the receiving end).
This is caused by the ph_start.time value being 0 for a 0-length file
(it's only initialized when the first hunk of data comes through for a
file).  I just checked-in a fix for this into CVS.

Interestingly, when pushing data, no progress was output at all for an
empty file.  Since this is inconsistent, I changed the code to produce
progress in both directions.
> I don't quite see the point of setting diff to 1ms if it's zero...
Because an elapsed time of 0 means that any data that arrived, arrived
very quickly.  Setting the rate to 0 when the elapsed time is 0 is the
opposite of what we need -- an infinite data rate.  I like the idiom of
changing the elapsed time from 0 to 1 so that it divides safely into the
quantity of sent data, and thus gives us a non-0 rate (if any data was
actually sent).

Thanks for pointing out the weird output!

..wayne..