unofficial mirror of guile-devel@gnu.org 
 help / color / mirror / Atom feed
* Profile of current guile HEAD
@ 2007-08-04 15:30 Andy Wingo
  2007-08-06  8:24 ` Ludovic Courtès
  0 siblings, 1 reply; 2+ messages in thread
From: Andy Wingo @ 2007-08-04 15:30 UTC (permalink / raw)
  To: guile-devel

Hey,

Some more data points. I just profiled a run of guile -c 1 from HEAD.
This is what callgrind says about which functions are taking the most
time:

cumulative   self      total
 percent    percent    calls    file:function
   23.15     19.30     151231   ports.c:scm_getc[/opt/guile-head/lib/libguile.so.18.0.0]
16928.38      7.08      12577   read.c:scm_read_expression[/opt/guile-head/lib/libguile.so.18.0.0]
    6.45      6.45      93110   ???:pthread_getspecific[/lib/libpthread-2.6.so]
    6.16      6.12        372   gc-card.c:scm_i_sweep_card[/opt/guile-head/lib/libguile.so.18.0.0]
  106.76      4.83       9747   inline.h:ceval[/opt/guile-head/lib/libguile.so.18.0.0]
    4.12      4.11      27101   ports.c:scm_ungetc[/opt/guile-head/lib/libguile.so.18.0.0]
   27.79      4.04      66030   gc-mark.c:scm_gc_mark[/opt/guile-head/lib/libguile.so.18.0.0]
   23.63      3.71      14562   gc-mark.c:scm_gc_mark_dependencies[/opt/guile-head/lib/libguile.so.18.0.0]
   17.20      2.93      28946   pairs.c:scm_cons[/opt/guile-head/lib/libguile.so.18.0.0]
    2.68      2.22       8810   symbols.c:lookup_interned_symbol[/opt/guile-head/lib/libguile.so.18.0.0]
  411.68      2.21      16758   inline.h:flush_ws[/opt/guile-head/lib/libguile.so.18.0.0]
    5.80      1.91          6   weaks.c:scm_i_mark_weak_vectors_non_weaks[/opt/guile-head/lib/libguile.so.18.0.0]
    2.38      1.74       2052   ???:0x0000AB30[/lib/ld-2.6.so]
    1.65      1.60      19977   ports.c:scm_fill_input[/opt/guile-head/lib/libguile.so.18.0.0]
    1.43      1.43        288   gc-card.c:scm_i_init_card_freelist[/opt/guile-head/lib/libguile.so.18.0.0]
   24.34      1.21     151126   ???:0x000DE440[/opt/guile-head/lib/libguile.so.18.0.0]
   18.50      1.16       8800   symbols.x:scm_i_c_mem2symbol[/opt/guile-head/lib/libguile.so.18.0.0]
    1.15      1.15       8810   hash.c:scm_string_hash[/opt/guile-head/lib/libguile.so.18.0.0]
    2.60      1.10       6674   alist.c:scm_acons[/opt/guile-head/lib/libguile.so.18.0.0]
    7.29      1.05       2052   ???:0x0000AFC0[/lib/ld-2.6.so]
    1.02      1.02       6572   ???:pthread_mutex_lock[/lib/libpthread-2.6.so]

There are more, of course. I think that the 0x0000* functions are the
PLT entries, which callgrind on PPC doesn't know how to filter out
(apparently).

The summary of this is that we (meaning, erm, Ludovic) kicked some ass
in making the reader not create so much garbage. The biggest win now
would probably be some kind of byte compilation so that the reader can
be simpler, strings and symbols can be encoded with their lengths, etc.
Probably older hands know of good strategies; is it normal that startup
cost is 40-50% in `read'?

I still think that the TLS patch can help with the pthread_getspecific
stuff; I should profile with that patch. Later maybe.

FWIW, here's a profile of (use-modules (oop goops)):

cumulative   self      total
 percent    percent    calls    file:function
   13.74     11.62     238008   ports.c:scm_getc[/opt/guile-head/lib/libguile.so.18.0.0]
 1332.06     10.32      56710   eval.i.c:ceval[/opt/guile-head/lib/libguile.so.18.0.0]
    9.31      9.31     351261   ???:pthread_getspecific[/lib/libpthread-2.6.so]
    7.92      7.88       1386   gc-card.c:scm_i_sweep_card[/opt/guile-head/lib/libguile.so.18.0.0]
  104.30      6.28      57497   gc-mark.c:scm_gc_mark_dependencies[/opt/guile-head/lib/libguile.so.18.0.0]
  109.48      5.00     207620   gc-mark.c:scm_gc_mark[/opt/guile-head/lib/libguile.so.18.0.0]
 9107.65      4.52      20827   read.c:scm_read_expression[/opt/guile-head/lib/libguile.so.18.0.0]
   15.28      2.83      73045   pairs.c:scm_cons[/opt/guile-head/lib/libguile.so.18.0.0]
    2.62      2.61      44968   ports.c:scm_ungetc[/opt/guile-head/lib/libguile.so.18.0.0]
    6.34      2.14         15   weaks.c:scm_i_mark_weak_vectors_non_weaks[/opt/guile-head/lib/libguile.so.18.0.0]
    8.65      1.79      28332   alist.c:scm_acons[/opt/guile-head/lib/libguile.so.18.0.0]
    1.77      1.46      14287   symbols.c:lookup_interned_symbol[/opt/guile-head/lib/libguile.so.18.0.0]
  231.59      1.35      27545   inline.h:flush_ws[/opt/guile-head/lib/libguile.so.18.0.0]
    1.41      1.05      17112   hashtab.c:scm_hash_fn_get_handle[/opt/guile-head/lib/libguile.so.18.0.0]
    1.05      1.01      33135   ports.c:scm_fill_input[/opt/guile-head/lib/libguile.so.18.0.0]

Reading is still probably the highest cost here, but seeing ceval so
high normally means that most of the time is spent in Scheme code.
Obviously a fair bit of garbage is being generated as well. Perhaps with
microoptimizations in scm_getc() (or avoiding calling it) and with the
TLS patch, we can lower (oop goops) load time to 1.6 levels.

Regards,

Andy.
-- 
http://wingolog.org/


_______________________________________________
Guile-devel mailing list
Guile-devel@gnu.org
http://lists.gnu.org/mailman/listinfo/guile-devel


^ permalink raw reply	[flat|nested] 2+ messages in thread

* Re: Profile of current guile HEAD
  2007-08-04 15:30 Profile of current guile HEAD Andy Wingo
@ 2007-08-06  8:24 ` Ludovic Courtès
  0 siblings, 0 replies; 2+ messages in thread
From: Ludovic Courtès @ 2007-08-06  8:24 UTC (permalink / raw)
  To: guile-devel

Hey!

Andy Wingo <wingo@pobox.com> writes:

> Some more data points. I just profiled a run of guile -c 1 from HEAD.
> This is what callgrind says about which functions are taking the most
> time:
>
> cumulative   self      total
>  percent    percent    calls    file:function
>    23.15     19.30     151231   ports.c:scm_getc[/opt/guile-head/lib/libguile.so.18.0.0]

This one ought to be inline, it's really just a few instructions.

> I still think that the TLS patch can help with the pthread_getspecific
> stuff; I should profile with that patch. Later maybe.

Wrt. TLS: GCC's default TLS access model (called `global-dynamic')
involves one function call for each TLS access, making it comparable to
using `pthread_getspecific ()' performance-wise.  I'm investigating
whether we can rightfully use one of the faster access models.
Hopefully more to come soon!

> FWIW, here's a profile of (use-modules (oop goops)):

[...]

> Reading is still probably the highest cost here, but seeing ceval so
> high normally means that most of the time is spent in Scheme code.

We must be spending time in `(oop goops compile)' or similar?

Cheers,
Ludovic.





_______________________________________________
Guile-devel mailing list
Guile-devel@gnu.org
http://lists.gnu.org/mailman/listinfo/guile-devel


^ permalink raw reply	[flat|nested] 2+ messages in thread

end of thread, other threads:[~2007-08-06  8:24 UTC | newest]

Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2007-08-04 15:30 Profile of current guile HEAD Andy Wingo
2007-08-06  8:24 ` Ludovic Courtès

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).