From: Pieter Praet <pieter@praet.org>
To: Austin Clements <amdragon@MIT.EDU>
Subject: Re: [PATCH] emacs: Use a single buffer invisibility spec to fix
	quadratic search cost.
In-Reply-To: <20111111052716.GU2658@mit.edu>
References: <1320807328-13728-1-git-send-email-amdragon@mit.edu>
	<877h382jax.fsf@SSpaeth.de>
	<CAPFwwQgsqe2NE9vm2RJHHK+8hWR_uMWKLHcxm0xkjduFboAfPw@mail.gmail.com>
	<87d3czxsu9.fsf@praet.org> <20111111045341.GS2658@mit.edu>
	<20111111052716.GU2658@mit.edu>
User-Agent: Notmuch/0.9+76~g2fd88e6 (http://notmuchmail.org) Emacs/23.3.1
	(x86_64-unknown-linux-gnu)
Date: Tue, 15 Nov 2011 17:47:46 +0100
Message-ID: <87d3ctjpsd.fsf@praet.org>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Cc: notmuch@notmuchmail.org, servilio <servilio@gmail.com>
Precedence: list

On Fri, 11 Nov 2011 00:27:16 -0500, Austin Clements <amdragon@MIT.EDU> wrote:
> Quoth myself on Nov 10 at 11:53 pm:
> > Quoth Pieter Praet on Nov 11 at  4:04 am:
> > > I've tried getting some hard numbers using
> > > 
> > >   #+begin_src sh
> > >     time emacs --eval '(progn
> > >         (notmuch)
> > >         (notmuch-search "*")
> > >         (while (get-buffer-process (current-buffer))
> > >             (sleep-for 0.1))
> > >         (kill-emacs))'
> > >   #+end_src
> > > 
> > > ... but the results vary wildly on subsequent runs.
> > 
> > For me, this doesn't actually display the results buffer (though I
> > don't know why not), which means it won't test this, since the problem
> > lies in the Emacs redisplay logic.
> 
> This may or may not actually be correct, but the following seems more
> representative on my system:
> 
>     time emacs --eval '(progn
>         (notmuch)
>         (notmuch-search "*")
>         (while (get-buffer-process (current-buffer))
>             (redisplay)
>             (sleep-for 0.1))
>         (kill-emacs))'
> 

Yup, that does the trick!

These remained fairly consistent, even with both CPU cores enabled:

|      |         SINGLE        |          DUAL         |
|      | before    | after     | before    | after     |
|------+-----------+-----------+-----------+-----------|
| real | 0m34.560s | 0m31.829s | 0m30.784s | 0m26.587s |
| user | 0m26.188s | 0m23.672s | 0m27.028s | 0m22.889s |
| sys  | 0m0.863s  | 0m0.907s  | 0m1.200s  | 0m1.243s  |


> This at least displays the buffer.  I also tried
> (accept-process-output) instead of the (sleep-for 0.1), which clearly
> behaved differently, but gave only slightly higher numbers.  If I
> timed just the search part, to exclude emacs start-up, I would have a
> better idea of which more closely matches my manual measurements.

Oddly enough...  I ran some tests using `elp-instrument-package' and
your `time-it' macro [1] to keep emacs init out of the equation, and
both not only produced horribly fluctuating results (even with only a
single CPU core enabled), but often took *longer* as well!

I'm stumped...

  #+begin_src emacs-lisp
    (progn
      (require 'notmuch)
      (let ((elp-reset-after-results t))
        (elp-instrument-package "notmuch")
        (notmuch-search "*")
        (while (get-buffer-process (current-buffer))
          (redisplay)
          (sleep-for 0.1))
        (elp-results)))
  #+end_src

  #+begin_src emacs-lisp
    (defmacro time-it (code)
      `(let ((start-time (get-internal-run-time)))
         ,code
         (float-time (time-subtract (get-internal-run-time) start-time))))

    (require 'notmuch)

    (time-it (progn
               (notmuch-search "*")
               (while (get-buffer-process (current-buffer))
                 (redisplay)
                 (sleep-for 0.1))))
  #+end_src


Peace

-- 
Pieter

[1] id:"20110713185721.GI25558@mit.edu"