From mboxrd@z Thu Jan 1 00:00:00 1970 Path: news.gmane.org!not-for-mail From: Andy Wingo Newsgroups: gmane.lisp.guile.devel Subject: Re: statprof working with guile-vm Date: Wed, 04 Feb 2009 01:31:02 +0100 Message-ID: References: <87zlh3i0xc.fsf@arudy.ossau.uklinux.net> NNTP-Posting-Host: lo.gmane.org Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii X-Trace: ger.gmane.org 1233707601 19396 80.91.229.12 (4 Feb 2009 00:33:21 GMT) X-Complaints-To: usenet@ger.gmane.org NNTP-Posting-Date: Wed, 4 Feb 2009 00:33:21 +0000 (UTC) Cc: guile-devel To: Neil Jerram Original-X-From: guile-devel-bounces+guile-devel=m.gmane.org@gnu.org Wed Feb 04 01:34:34 2009 Return-path: Envelope-to: guile-devel@m.gmane.org Original-Received: from lists.gnu.org ([199.232.76.165]) by lo.gmane.org with esmtp (Exim 4.50) id 1LUVio-00022C-LC for guile-devel@m.gmane.org; Wed, 04 Feb 2009 01:34:30 +0100 Original-Received: from localhost ([127.0.0.1]:39569 helo=lists.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1LUVhV-00013Z-Be for guile-devel@m.gmane.org; Tue, 03 Feb 2009 19:33:09 -0500 Original-Received: from mailman by lists.gnu.org with tmda-scanned (Exim 4.43) id 1LUVhI-000113-Ni for guile-devel@gnu.org; Tue, 03 Feb 2009 19:32:56 -0500 Original-Received: from exim by lists.gnu.org with spam-scanned (Exim 4.43) id 1LUVhH-00010D-Qx for guile-devel@gnu.org; Tue, 03 Feb 2009 19:32:56 -0500 Original-Received: from [199.232.76.173] (port=59706 helo=monty-python.gnu.org) by lists.gnu.org with esmtp (Exim 4.43) id 1LUVhH-000106-MQ for guile-devel@gnu.org; Tue, 03 Feb 2009 19:32:55 -0500 Original-Received: from a-sasl-quonix.sasl.smtp.pobox.com ([208.72.237.25]:59287 helo=sasl.smtp.pobox.com) by monty-python.gnu.org with esmtp (Exim 4.60) (envelope-from ) id 1LUVhH-0005zE-AA for guile-devel@gnu.org; Tue, 03 Feb 2009 19:32:55 -0500 Original-Received: from localhost.localdomain (unknown [127.0.0.1]) by b-sasl-quonix.sasl.smtp.pobox.com (Postfix) with ESMTP id 0BECD2A626; Tue, 3 Feb 2009 19:32:53 -0500 (EST) Original-Received: from unquote (unknown [83.36.114.236]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by b-sasl-quonix.sasl.smtp.pobox.com (Postfix) with ESMTPSA id 48CC92A622; Tue, 3 Feb 2009 19:32:51 -0500 (EST) In-Reply-To: <87zlh3i0xc.fsf@arudy.ossau.uklinux.net> (Neil Jerram's message of "Tue, 03 Feb 2009 22:57:19 +0000") User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/23.0.60 (gnu/linux) X-Pobox-Relay-ID: 5BFA712C-F253-11DD-99A6-6F7C8D1D4FD0-02397024!a-sasl-quonix.pobox.com X-detected-operating-system: by monty-python.gnu.org: Solaris 10 (beta) X-BeenThere: guile-devel@gnu.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: "Developers list for Guile, the GNU extensibility library" List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Original-Sender: guile-devel-bounces+guile-devel=m.gmane.org@gnu.org Errors-To: guile-devel-bounces+guile-devel=m.gmane.org@gnu.org Xref: news.gmane.org gmane.lisp.guile.devel:8131 Archived-At: On Tue 03 Feb 2009 23:57, Neil Jerram writes: > Andy Wingo writes: > >> Statprof works for profiling guile-vm. > > Looks good. Thanks. > And I see some more recent commits on renaming lambdas, is that to > address the multiple occurrences of retrans and lp? No. Statprof reports procedures by identity (i.e. `eq?'), not by name; but it discards procedures that have no names on the grounds that you don't really know what those procedures are. That commit was to give names to procedures bound like (letrec ((foo (lambda ...)))). But come to think of it, we should be able to do better, reporting based on identity of source location (as determined for example by eq? on program-objcode, or on interpreted closure code) instead of on procedure (closure) identity. > Where is statprof at the moment? Guile-lib > If it's now unlikely to change dramatically, it feels to me that it > should move into Guile core. What do you think? I agree, though there are some documentation things to take care of. It was only written by Rob Browning, and modified a bit by myself. Statprof on the vm is slightly different due to tail recursion -- the debugging evaluator keeps some of those frames on the debug stack. Surprising. Also here's the current GOOPS profile: scheme@(guile-user)> (use-modules (statprof)) scheme@(guile-user)> (with-statprof #:hz 1000 (resolve-module '(oop goops))) % cumulative self time seconds seconds name 18.18 0.10 0.04 for-each 7.58 0.03 0.02 byte-length 7.58 0.02 0.02 record-predicate 4.55 0.06 0.01 glil->assembly 3.03 0.21 0.01 load-compiled/vm 3.03 0.08 0.01 write-bytecode 3.03 0.01 0.01 lookup-transformer 3.03 0.01 0.01 ghil-env-add! 3.03 0.01 0.01 list-index 3.03 0.01 0.01 cache-try-hash! 1.52 0.05 0.00 map 1.52 0.01 0.00 lp 1.52 0.01 0.00 make-glil-program 1.52 0.01 0.00 eqv? 1.52 0.01 0.00 %init-goops-builtins [...] 0.00 0.21 0.00 dynamic-wind 0.00 0.20 0.00 memoize-method! 0.00 0.19 0.00 compute-entry-with-cmethod 0.00 0.19 0.00 compile-fold 0.00 0.19 0.00 compile-method/vm 0.00 0.18 0.00 make-instance 0.00 0.18 0.00 initialize 0.00 0.08 0.00 compute-cmethod 0.00 0.08 0.00 %goops-loaded 0.00 0.08 0.00 make-extended-generic 0.00 0.08 0.00 make-next-method 0.00 0.08 0.00 compile-bytecode 0.00 0.06 0.00 ensure-generic 0.00 0.06 0.00 compile-asm 0.00 0.06 0.00 compile-assembly 0.00 0.04 0.00 save-module-excursion 0.00 0.03 0.00 compile-glil 0.00 0.03 0.00 codegen 0.00 0.02 0.00 call-with-ghil-bindings 0.00 0.02 0.00 load-file 0.00 0.02 0.00 add-method! 0.00 0.02 0.00 translate-1 0.00 0.01 0.00 record-accessor [...] Sample count: 66 Total time: 0.21 seconds (2/25 seconds in GC) I think the salient point here is that out of 0.21 seconds of loading GOOPS, 0.19 of it is spent in the compiler (see `compile-fold'). Besides that, there are like 60000 closures created, which is a bit excessive. That number is from valgrind. Also these numbers do match well with the valgrind numbers. I think there's still 10-20% of low-hanging fruit, but the algorithmic improvements are really where we're going to win. Anyway, late night ramblings. Hasta luego, Andy -- http://wingolog.org/