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"