unofficial mirror of guile-devel@gnu.org 
 help / color / mirror / Atom feed
* slowness in guile 1.8
@ 2007-05-25 16:33 Andy Wingo
  2007-05-25 18:12 ` Ludovic Courtès
  0 siblings, 1 reply; 8+ messages in thread
From: Andy Wingo @ 2007-05-25 16:33 UTC (permalink / raw)
  To: guile-devel

[-- Attachment #1: Type: text/plain, Size: 1520 bytes --]

Hello guile devs,

I am doing some profiling with guile-gnome and guile 1.8. It is
significantly slower than 1.6. One reason in guile-gnome is the thinking
behind e.g. this change from 2004:

2004-12-22  Marius Vollmer  <marius.vollmer@uni-dortmund.de>

	* boot-9.scm (module-make-local-var!): When creating a new
	variable, initialize it to the value of any imported variable with
	the given name.  This allows code like (define round round) to
	work as expected.

(There were previous changes when duplicate handlers were introduced in
2003 by Mikael.)

This scheme code gets called whenever a variable is defined. The fact
that guile goes through module-variable and module binders, etc etc, to
compute what a value would have been *and then we throw it away*, is
quite wasteful. I'm attaching a statprof log from loading (gnome gtk);
out of 6.2 seconds loading the module (!), fully 3.8 of them were inside
module-variable. Of course profiling interpretation is not that simple,
but I think the trace shows a significant regression from 1.6, where I
was able to get (gnome gtk) loading down to less than 2 seconds, which
is still too much.

In this particular case the solution would be to compute the value
before computing the variable in which to store it. Computing the
variable in which to store is then O(1) in the number of modules in the
system, as it doesn't have to search the use list.

Any thoughts on this? Sometimes I think I'm just ranting to an empty
room ;)

Cheers,

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

[-- Attachment #2: gnome-gtk-statprof --]
[-- Type: text/plain, Size: 6397 bytes --]

guile> (with-statprof #:hz 100 (resolve-interface '(gnome gtk)))
%     cumulative   self             
time   seconds     seconds      name
 16.55      1.13      1.03  hash-for-each
 12.41      3.81      0.77  module-search
 11.38      1.24      0.71  %record-type-check
 10.69      2.18      0.66  module-local-variable
  5.17      0.94      0.32  module-obarray-ref
  5.17      0.66      0.32  module-obarray
  5.17      0.32      0.32  record-type-descriptor
  3.79      0.56      0.24  eq?
  2.76      4.06      0.17  module-make-local-var!
  2.76      0.60      0.17  module-binder
  2.41      0.60      0.15  module-uses
  2.07      6.20      0.13  primitive-load
  1.72      1.62      0.11  for-each
  1.03      0.13      0.06  catch
  1.03      0.06      0.06  cache-hashval
  0.69      4.21      0.04  dynamic-call
  0.69      0.21      0.04  module-ensure-local-variable!
  0.69      0.09      0.04  module-obarray-set!
  0.69      0.06      0.04  vector-set!
  0.34      0.15      0.02  module-add!
  0.34      0.11      0.02  module-modified
  0.34      0.11      0.02  add-method!
  0.34      0.09      0.02  vector-map
  0.34      0.09      0.02  module-ref
  0.34      0.06      0.02  module-call-observers
  0.34      0.04      0.02  module-observers
  0.34      0.02      0.02  module-weak-observers
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  not
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  module-for-each
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  gtype-class->type
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  hash-set!
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  make-module
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.34      0.02      0.02  loop
  0.00      6.20      0.00  resolve-module
  0.00      6.20      0.00  try-load-module
  0.00      6.20      0.00  dynamic-wind
  0.00      6.20      0.00  try-module-autoload
  0.00      6.20      0.00  load-file
  0.00      6.20      0.00  resolve-interface
  0.00      6.20      0.00  primitive-eval
  0.00      6.20      0.00  save-module-excursion
  0.00      6.20      0.00  with-fluid*
  0.00      5.67      0.00  process-use-modules
  0.00      4.77      0.00  map
  0.00      4.75      0.00  apply
  0.00      3.81      0.00  module-variable
  0.00      3.29      0.00  load-file
  0.00      1.18      0.00  module-use-interfaces!
  0.00      1.15      0.00  process-duplicates
  0.00      0.98      0.00  load-file
  0.00      0.47      0.00  process-define-module
  0.00      0.43      0.00  module-export!
  0.00      0.36      0.00  load-file
  0.00      0.34      0.00  load-file
  0.00      0.30      0.00  loop
  0.00      0.24      0.00  initialize
  0.00      0.24      0.00  make-instance
  0.00      0.19      0.00  %gw-module-binder
  0.00      0.19      0.00  gtype->class
  0.00      0.17      0.00  gobject-class-set-properties!
  0.00      0.15      0.00  method-cache-install!
  0.00      0.15      0.00  memoize-method!
  0.00      0.13      0.00  cache-try-hash!
  0.00      0.13      0.00  hashed-method-cache-insert!
  0.00      0.13      0.00  get-direct-supers
  0.00      0.09      0.00  %gw-module-binder
  0.00      0.09      0.00  load-file
  0.00      0.09      0.00  gobject-type-get-properties
  0.00      0.09      0.00  make-class
  0.00      0.09      0.00  defined?
  0.00      0.06      0.00  loop
  0.00      0.06      0.00  cons*
  0.00      0.06      0.00  logand
  0.00      0.06      0.00  module-public-interface
  0.00      0.04      0.00  load-file
  0.00      0.04      0.00  init-gobject-class
  0.00      0.04      0.00  especify-metaclass!
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  compute-new-list-of-methods
  0.00      0.02      0.00  hash-fold
  0.00      0.02      0.00  beautify-user-module!
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  list
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  compile-method
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  module-use!
  0.00      0.02      0.00  load-file
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  next-method?
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  init-gobject-class
  0.00      0.02      0.00  compute-entry-with-cmethod
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  class-of
  0.00      0.02      0.00  slot-set!
  0.00      0.02      0.00  memv
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  loop
  0.00      0.02      0.00  compute-slot-accessors
  0.00      0.02      0.00  find-duplicate
  0.00      0.02      0.00  loop
---
Sample count: 290
Total time: 6.2 seconds (9/10 seconds in GC)

[-- Attachment #3: Type: text/plain, Size: 143 bytes --]

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

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

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

Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2007-05-25 16:33 slowness in guile 1.8 Andy Wingo
2007-05-25 18:12 ` Ludovic Courtès
2007-05-26 10:49   ` Andy Wingo
2007-05-26 10:57     ` Andy Wingo
2007-05-26 13:15     ` Ludovic Courtès
2007-05-26 14:45       ` Ludovic Courtès
2007-05-26 15:39         ` Andy Wingo
2007-06-13 22: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).