Slow "bzr branch" on Savannah (was: Performance of bzr update for lightweight checkout)

Tue Feb 8 19:19:02 UTC 2011

> From: Eric Siegerman <lists08-bzr at davor.org>
> Date: Sat, 05 Feb 2011 11:23:09 -0500
> 
> On Sat, 2011-02-05 at 15:28 +0200, Eli Zaretskii wrote:
> > Date: Sat, 5 Feb 2011 14:13:20 +0100
> > > From: Ulrich Mueller <ulm at gentoo.org>
> > 
> > > And as I said before, for lp:emacs it was only 15 minutes.
> > 
> > But that one is not necessarily up to date.
> 
> I don't know why the download times from Launchpad and Savannah
> are so different, unless, as has been suggested, it's a simple
> lack of resources at their end.  Actually, here's another stab in
> the dark: I wonder if Savannah is running a pure-python bzr,
> without the compiled extensions.  Would that account for such a
> large speed difference on this particular operation?

I did some measurements over the last 2 days.  The results are
disappointing, to say the least.  In particular, my responses were
unduly optimistic, as the times I remembered are no longer
representative, see below.

I would appreciate if someone on the Bazaar development team would
contact the Savannah admins and advise them how to improve the speed
of the initial "bzr branch", so that it's closer to the speed we get
with Launchpad.  While it's true that the initial branch is a one-time
operation, such disastrously long times will definitely avert
potential contributors.  In fact, we already had a few of them
(fortunately, a small number for now) that abandoned bzr, and at least
one stopped tracking the trunk completely.  As the number of revisions
grows, I'm afraid we will face more of that in the future.  People
simply refuse to wait for hours to get the initial branch.

Note that there are no significant complaints about the speed of the
subsequent "bzr update" and "bzr commit" operations, they are quite
fast.

The measurements below are all for the initial "bzr branch" command,
in a repository freshly created with the "bzr init-repo" command
without any switches.  I tried 3 URLs:

  . lp:emacs
  . bzr://bzr.savannah.gnu.org/emacs/trunk
  . bzr+ssh://MYID@bzr.savannah.gnu.org/emacs/trunk

(where MYID is my Savannah user ID).  I also give branch times for the
SFTP protocol, from a year ago (99K revisions vs 103K now), taken from
my .bzr.log on each system.

The measurements were done on 2 different systems:

  . a Windows XP box far away from Savannah (ping reports turnaround
    times of 150ms), connected to a 20Mbps link, with bzr 2.2.3
  . one of gnu.org machines, an x86_64 GNU/Linux system connected to
    the same LAN as bzr.savannah.gnu.org, with bzr 2.1.1

The bottom line is: Launchpad is almost always faster than
bzr.savannah.gnu.org.  That the times are so long even for the
GNU/Linux system sitting on the same LAN as the server is in itself
almost unbelievable.  How can it be that the "smart server" is 2 to 3
times _slower_ than the "dumb" SFTP protocol, both over LAN and over
WAN?

One thing that I noticed was that the initial "Find revisions" phase
takes only 1.5 minutes with Launchpad, but is painstakingly slow with
bzr.savannah: I saw times between 17 and 55 minutes(!).  Also, at
least for bzr+ssh, there are prolonged periods of time that bzr is
waiting for the server, doing nothing (there's no CPU or disk
activity, and no network traffic).  Even the network throughput
numbers I find in .bzr.log (reproduced below) are abysmally small for
a LAN.

What does Launchpad know or do that bzr.savannah doesn't?

The detailed results are as follows:

  1) lp:emacs

     a) GNU/Linux:

        time:

          real    47m31.014s
          user    16m31.510s
          sys     0m14.000s

        network:

          Transferred: 675470KiB (237.1K/s r:675004K w:467K)

     b) Windows:

        time:

          real    01h04m01.629s
          user    00h20m54.484s
          sys     00h00m57.046s

        network:

          Transferred: 676975kB (176.3kB/s r:676479kB w:496kB)

  2) bzr://bzr.savannah.gnu.org/emacs/trunk

     a) GNU/Linux:

        time:

          real    45m4.820s
          user    15m58.380s
          sys     0m12.910s

        network:

          Transferred: 540480KiB (199.9K/s r:540403K w:77K)

     b) Windows:

        time:

          real    02h13m52.949s
          user    00h15m37.828s
          sys     00h00m39.578s

        network:

          Transferred: 552961kB (68.9kB/s r:552882kB w:79kB)

  3) bzr+ssh://MYID@bzr.savannah.gnu.org/emacs/trunk

     a) GNU/Linux:

        time:

          real    39m6.798s
          user    14m17.740s
          sys     0m11.640s

        network:

          Transferred: 540001KiB (230.2K/s r:539924K w:77K)

     b) Windows:

        time:

          real    02h27m03.017s
          user    00h28m17.875s
          sys     00h03m11.984s

        network:

          Transferred: 553565kB (62.8kB/s r:553487kB w:78kB)

  4) sftp://MYID@bzr.savannah.gnu.org/srv/bzr/emacs/trunk/

     a) GNU/Linux:

        time: 15 min

     b) Windows:

        time: 56 min

These numbers are consistent, I repeated each attempt several times
and got similar results.

Oh, and when I use Launchpad, I see many lines like this in .bzr.log:

   3705.648  25 bytes left on the HTTP socket

Looks like some debug message left behind.