Speedup with history-db

Eli Zaretskii eliz at gnu.org
Fri May 27 13:18:20 UTC 2011 

> Date: Fri, 27 May 2011 13:30:25 +0200
> From: John Arbash Meinel <john at arbash-meinel.com>
> CC: bazaar at lists.canonical.com
> 
> >     D:\gnu\bzr\emacs\trunk>timep bzr log --include-merges -c104363 >nul
> > 
> >     real    00h00m47.453s
> >     user    00h00m45.125s
> >     sys     00h00m02.125s
> > 
> >     It takes 10.3s without history-db, so there's a 4.5 times
> >     slowdown with the DB.  Why is that?
> 
> I don't have a specific idea here, though we can investigate. "bzr
> - --lsprof-file foo.txt" can be enlightening.

It looks like the reason has nothing to do with speed, it's the same
or similar issue as with this command:

> >   . The output of "bzr log -n0 -r101290.1.25..101290.1.32" is
> >     different with and without the plugin.

The problem is that with the plugin, the produced output is huge, I
just didn't see it because I redirected it to the null device.
Without the plugin, the command displays just this:

  D:\gnu\bzr\emacs\trunk>bzr --no-plugins log --include-merges -c104363
  104363: Glenn Morris 2011-05-25 [merge] Merge from emacs-23; up to r100587.
    99634.2.953: YAMAMOTO Mitsuharu 2011-05-25 Take account of periodic fringe..
    99634.2.952: Kenichi Handa 2011-05-25 [merge] xdisp.c (get_next_display_el..
      99634.12.18: Kenichi Handa 2011-05-25 [merge] merge emacs-23
      99634.12.17: Kenichi Handa 2011-05-25 xdisp.c (get_next_display_element)..
      99634.12.16: Kenichi Handa 2011-05-23 [merge] merge emacs-23
      99634.12.15: Kenichi Handa 2011-05-23 [merge] merge emacs-23

which is what I'd expect.  With the plugin, it displays the same, but
then goes on displaying all the rest of the revisions all the way to
revno 1!  It's a small wonder that 16.6 seconds are taken by this:

     115006   0  16.6014      2.7581   <bzrlib\log.pyo>:1708(log_string)

So this change in the output of "bzr log" caused by the plugin is
really something to look into.

> If 104363 was really old, I could see bzr-history-db getting slower.

It's not old, the latest revision is 104384.

> For example, would expect history-db is probably slower for bzr log -r 10.

It is only marginally slower: 18.5s vs 17.4s without the plugin.  I
wouldn't consider it an issue, as the overhead is les than a second.

> >   . The output of "bzr log -n0 -r101290.1.25..101290.1.32" is
> >     different with and without the plugin.  I can send you the two
> >     outputs, but you can easily create them yourself (with the current
> >     Emacs trunk).  I actually don't understand well enough the
> >     semantics of this command, as it displays much more revisions than
> >     I'd expect (or maybe there's an unrelated bug in bzr), but the
> >     differences introduced by the plugin are disturbing anyway.
> > 
> 
> If the output itself is different, that is a bit worrisome.

It is really different.  Let me show you just the beginning.  With the
plugin:

  101290.1.32: Kenichi Handa 2011-05-20 [merge] merge trunk
  101290.1.31: Kenichi Handa 2011-05-20 composite.c (find_automatic_composition): Fix previous change.
  101290.1.30: Kenichi Handa 2011-05-20 [merge] merge trunk
  101290.1.29: Kenichi Handa 2011-05-18 merge trunk
  101290.1.28: Kenichi Handa 2011-05-18 [merge] merge trunk
  101290.1.27: Kenichi Handa 2011-04-15 [merge] merge trunk
  101290.1.26: Kenichi Handa 2011-03-30 [merge] merge trunk
  101290.1.25: Kenichi Handa 2011-02-23 [merge] merge trunk
  104291: Nix 2011-05-20 Small break-hardlink-on-save fix.
  104290: Glenn Morris 2011-05-20 Auto-commit of generated files.
  104289: Glenn Morris 2011-05-20 Remove $shortlisp from src/Makefile.in.
  104288: Katsumi Yamaoka 2011-05-20 mm-bodies.el (mm-decode-content-transfer-encoding): Allow leading whitespace in base64 data lines.
  104287: Deniz Dogan 2011-05-19 * lisp/net/rcirc.el (rcirc-markup-urls): Check if rcirc-url-regexp is nil.
  104286: Deniz Dogan 2011-05-19 * lisp/net/rcirc.el (rcirc-mode): Initialize rcirc-urls to nil.
  104285: Glenn Morris 2011-05-19 Fix whitespace in previous change.
  104284: Glenn Morris 2011-05-19 * doc/lispref/lists.texi (Sets And Lists): Mention cl provides union etc.
  104283: Nix 2011-05-19 Misc small lispref fixes.
  104282: Glenn Morris 2011-05-19 Auto-commit of generated files.
  104281: Glenn Morris 2011-05-19 * lisp/progmodes/f90.el (f90-type-def-re): Handle "type, bind(c)".  (Bug#8691)
  104280: Glenn Morris 2011-05-19 Remove the SOME_MACHINE_LISP distinction in src/Makefile.in.
  104279: Kenichi Handa 2011-05-19 [merge] Make find_automatic_composition more efficient.
    100145.1.4: Kenichi Handa 2011-05-19 [merge] merge trunk
    100145.1.3: Kenichi Handa 2011-05-18 Make find_automatic_composition more efficient.

without:

  101290.1.32: Kenichi Handa 2011-05-20 [merge] merge trunk
  101290.1.31: Kenichi Handa 2011-05-20 composite.c (find_automatic_composition): Fix previous change.
  101290.1.30: Kenichi Handa 2011-05-20 [merge] merge trunk
  101290.1.29: Kenichi Handa 2011-05-18 merge trunk
  101290.1.28: Kenichi Handa 2011-05-18 [merge] merge trunk
  101290.1.27: Kenichi Handa 2011-04-15 [merge] merge trunk
  101290.1.26: Kenichi Handa 2011-03-30 [merge] merge trunk
  101290.1.25: Kenichi Handa 2011-02-23 [merge] merge trunk
  103400: Glenn Morris 2011-02-23 * etc/NEWS: Typo fixes.
  103399: Glenn Morris 2011-02-23 * etc/NEWS: Remove some sql-stuff that is not NEWS-worthy.
  103398: Glenn Morris 2011-02-23 Comment spelling fix.
  103397: Glenn Morris 2011-02-23 * admin/notes/bzr: More details about merging ChangeLogs.
  103396: Glenn Morris 2011-02-23 [merge] Merge from emacs-23; up to r100498.
    99634.2.864: Glenn Morris 2011-02-23 * doc/misc/dired-x.texi (Features, Local Variables): Fix typos.
    99634.2.863: Kenichi Handa 2011-02-23 [merge] mail/rmailmm.el (rmail-mime-process-multipart): Do not signal an error when a multipart boundary in the nested multipart is found.
      99634.15.52: Kenichi Handa 2011-02-23 mail/rmailmm.el (rmail-mime-process-multipart): Do not signal an error when a multipart boundary in the nested multipart is found.
      99634.15.51: Kenichi Handa 2011-02-23 [merge] merge emacs-23
      99634.15.50: Kenichi Handa 2011-02-22 [merge] merge emacs-23
      99634.15.49: Kenichi Handa 2011-02-22 Decode "encoded-words" of header components on replying.
      99634.15.48: Kenichi Handa 2011-02-17 Fix font-size handling bug.
      99634.15.47: Kenichi Handa 2011-02-17 [merge] merge emacs-23
      99634.15.46: Kenichi Handa 2011-01-31 [merge] merge emacs-23
    99634.2.862: Kenichi Handa 2011-02-22 [merge] Fix font size handling.
      99634.19.7: Kenichi Handa 2011-02-22 Fix font size handling.
    99634.2.861: Kenichi Handa 2011-02-22 [merge] In rmail, decode "encoded-words" of header components on replying.
      99634.19.6: Kenichi Handa 2011-02-22 [merge] merge emacs-23
      99634.19.5: Kenichi Handa 2011-02-22 In rmail, decode "encoded-words" of header components on replying.
      99634.19.4: Kenichi Handa 2011-02-22 [merge] merge emacs-23
    99634.2.860: Juanma Barranquero 2011-02-22 admin/notes/bugtracker (bugtracker_debbugs_url): Fix typo.

> As for the range you are giving, that seems really weird to me. Since
> those aren't clearly derived from each other.

Sorry, I don't follow: the revisions in the range
101290.1.25..101290.1.32 all came from the same local branch that was
merged onto the trunk in revision 104292.  Why do you say they were
not derived from each other?

> Remember that "bzr log -r X..Y" is not show me all the changes in Y
> that aren't in X

Well, as I said, the semantics of this isn't entirely clear to me.
The documentation says:

  When logging a range of revisions using -rX..Y, log starts at
  revision Y and searches back in history through the primary
  (“left-hand”) parents until it finds X.

But since these revisions are from a branch, it isn't clear to me what
result I should expect from "searching back through the primary
parents" when the revisions are all on a branch.

More information about the bazaar mailing list