Changeset 9193

Apr 19, 2008, 4:07:04 AM (13 years ago)


2 edited


  • trunk/source/library/chud-metering.lisp

    r9187 r9193  
    11;;;-*-Mode: LISP; Package: (CHUD (:USE CL CCL)) -*-
    3 ;;;   Copyright (C) 2005 Clozure Associates and contributors
     3;;;   Copyright (C) 2005,2008 Clozure Associates and contributors
    44;;;   This file is part of OpenMCL. 
    2525(defpackage "CHUD"
    2626  (:use "CL" "CCL")
     27  (:export "METER" "*SHARK-CONFIG-FILE*"))
    3029(in-package "CHUD")
    78 (defvar *shark-process* nil)
    79 (defvar *sampling* nil)
     77(defloadvar *shark-process* nil)
     78(defloadvar *sampling* nil)
     80(defloadvar *debug-shark-process-output* nil)
    122123(defun identify-functions-with-pure-code ()
     124  (ccl::freeze)
    123125  (ccl::collect ((functions))
    124126    (block walk
    137139(defun identify-functions-with-pure-code ()
     140  (ccl:purify)
    138141  (multiple-value-bind (pure-low pure-high)
    173178(defun generate-shark-spatch-file ()
    174   #+ppc-target (ccl::purify)
    175   #+x86-target (ccl::freeze)
    176179  (let* ((functions (identify-functions-with-pure-code)))
    177180    (with-open-file (f (make-pathname
    231234        (do* ((line (read-line output nil nil) (read-line output nil nil)))
    232235             ((null line))
    233           (format t "~&~a" line)
     236          (when *debug-shark-process-output*
     237            (format t "~&~a" line))
    234238          (when (search "ready." line :key #'char-downcase)
    235239            (sleep 1)
    247251        (do* ((line (read-line out nil nil) (read-line out nil nil)))
    248252             ((null line))
    249           (format t "~&~a" line)
     253          (when *debug-shark-process-output*
     254            (format t "~&~a" line))
    250255          (when (search "Created session file:" line)
    251256            (display-shark-session-file line)
    256 (defmacro meter (form &key reset)
     261(defmacro meter (form &key reset debug-output)
    257262  (let* ((hook (gensym))
    258263         (block (gensym))
    264269                 (setq *shark-process* nil
    265270                       *sampling* nil))))
    266       (ensure-shark-process ,reset #',hook)
    267       (unwind-protect
    268          (progn
    269            (enable-sampling)
    270            ,form)
    271         (disable-sampling)
    272         (let* ((,process *shark-process*))
    273           (when ,process
    274             (scan-shark-process-output ,process))))))))
     271        (let* ((*debug-shark-process-output* ,debug-output))
     272          (ensure-shark-process ,reset #',hook)
     273          (unwind-protect
     274               (progn
     275                 (enable-sampling)
     276                 ,form)
     277            (disable-sampling)
     278            (let* ((,process *shark-process*))
     279              (when ,process
     280                (scan-shark-process-output ,process)))))))))
     282;;; Try to clean up after ourselves when the lisp quits.
     283(pushnew 'terminate-shark-process ccl::*save-exit-functions*)
  • trunk/source/library/chud-metering.txt

    r2594 r9193  
    1 Using Apple's CHUD metering tools from OpenMCL
     1Using Apple's CHUD metering tools from CCL
    3  Prerequisites
    57Apple's CHUD metering tools are available (as of this writing) from:
    9 There are also some CHUD packages distributed with some recent
    10 versions of Xcode; the standalone versions available via FTP seem to
    11 work much better with the OpenMCL interface. Both versions 4.1.1 and
    12 4.2.2 of the CHUD tools seem to work reasonably well; earlier versions
    13 provide a different ABI, and it's not known whether any future
    14 versions will be compatible.
     11The CHUD tools are also generally bundled with Apple's XCode tools.
     12CBUD 4.5.0 (which seems to be bundled with XCode 3.0) seems to work
     13well with this interface; later versions may have problems.
     14Versions of CHUD as old as 4.1.1 may work with 32-bit PPC versions
     15of CCL; later versions (not sure exactly -what- versions) added
     16x86, ppc64, and x86-64 support.
    16 There don't seem to be any versions of CHUD that can deal with 64-bit
    17 processes.
     18One way to tell whether any version of the CHUD tools is installed
     19is to try to invoke the "shark" command-line program (/usr/bin/shark)
     20from the shell:
    19 Ensure that either version 4.1.1 or 4.2.2 of the CHUD tools are
    20 installed. One side-effect of installation is that the folder "
    21 /Developer/Applications/Performance Tools" will have been created and
    22 will contain an application called "Shark". Double-click on Shark; in
    23 its "Preferences" window's "Search Paths" pane, use the "+" button to
    24 add your home directory to the "Patch Files" search path.
     22shell> shark --help
    26  Background
     24and verifying that that prints a usage summary.
    28 CHUD's Shark application is a user interface to its low-level
    29 performance monitoring facilities; those facilities provide access to
    30 high-resolution timers, on-chip debugging information, and OS
    31 performance counters. Shark allows the user to run sampling sessions,
    32 which record information about the context in which sampling events
    33 (such as timer interrupts) occur; at the end of the session, Shark
    34 processes the sampled data and presents a browsable interface which
    35 shows the processes, threads, and functions associated with those
    36 events.
     26CHUD consists of several components, including command-line programs,
     27GUI applications, kernel extensions, and "frameworks" (collections of
     28libraries, headers, and other resources which applications can use to
     29access functionality provided by the other components.)  Past versions
     30of CCL/OpenMCL have used the CHUD framework libraries to control the
     31CHUD profiler.  Even though the rest of CHUD is currently 64-bit aware,
     32the frameworks are unfortunately still only available as 32-bit libraries,
     33so the traditional way of controlling the profiling facility from OpenMCL
     34has only worked from DarwinPPC32 versions.
    38 For many processes, Shark can identify functions (the range of
    39 addresses corresponding to the address of the first and last
    40 instructions in the function) by interpreting symbolic information
    41 contained in the executable file. This strategy enables it to identify
    42 C and assembler functions in OpenMCL's lisp kernel, but doesn't help
    43 much in identifying Lisp functions. Fortunately, Shark does have the
    44 ability to read "patch files" , which associate symbolic names to
    45 regions of a process's address space), and fortunately OpenMCL can be
    46 told to move the machine code (the "code vector") associated with a
    47 compiled function to a static memory area (so that the addresses of
    48 the first and last instructions in a compiled lisp function remain
    49 constant); it's possible to assign fixed addresses to the code vectors
    50 of all functions in the lisp at a given time, and to give symbolic
    51 names to the memory regions that delimit those code vectors.
     36Two of the CHUD component programs are of particular interest:
    53 The process of moving code vectors to a static (and incidentally
    54 read-only) memory area is sometimes referred to as "purification".
     381) The "Shark" application (often installed in
     39"/Developer/Applications/Performance Tools/"), which provides
     40a graphical user interface for exploring and analyzing profiling results
     41and provides tools for creating "sampling configurations" (see below),
     42among other things.
    56  A Sampling Sample
     442) the "shark" program ("/usr/bin/shark"), which can be used to control
     45the CHUD profiling facility and to collect sampling data, which can then
     46be displayed and analyzed in
    58 There's a little bit of flexibility in the order in which these steps
    59 are performed, but for the sake of argument we'll pretend here that
    60 there isn't.
     48The fact that these two (substantially different) programs have names that
     49differ only in alphabetic case may be confusing.  The discussion below
     50tries to consistently distinguish between "the shark program" and "the
     51Shark application".
    62 1) Run Shark, and put it in "remote" mode.
     53Usage synopsis
    64 Run Shark. Ensure that it's in "Programmatic (Remote)" mode by
    65 selecting that option from the "Sampling" menu, or by pressing the key
    66 equivalent "command-shift-R". In the main Shark window, ensure that
    67 the sampling type is set to "Time Profile", select "Process" (instead
    68 of "Everything" ) from the next popup, and doing so should cause the
    69 third popup to select "Remote Client".
     56? (defun fact (n) (if (zerop n) 1 (* n (fact (1- n)))))
     58? (require "CHUD-METERING")
     61? (chud:meter (null (fact 10000)))
     62NIL           ; since that large number is not NULL
    71 2) Meter some code in OpenMCL.
     64and, a few seconds after the result is returned, a file whose
     65name is of the form "session_nnn.mshark" will open in
    73 In OpenMCL, do:
     67The fist time that CHUD:METER is used in a lisp session, it'll do a
     68few things to prepare subsequent profiling sessions.  Those things
    75 ? (require "CHUD-METERING")
     711) creating a directory to store files that are related to using
     72the CHUD tools in this lisp session.  This directory is created in
     73the user's home directory and has a name of the form:
    77 and ensure that the code that you want to profile is defined.
    79 ? (defun fact (n)
    80     (if (zerop n)
    81       1
    82       (* n (fact (1- n)))))
    83 FACT
    84 ? (defun fact-n-m-times (m n)
    85     (dotimes (i m)
    86       (fact n)))
     77where <pid> is the lisp's process id, <lisp-kernel> is the name of
     78the lisp kernel (of all things ...), and the other values provide
     79a timestamp.
    89 Then run something with metering enabled:
     812) does whatever needs to be done to ensure that currently-defined
     82lisp functions don't move around as the result of GC activity, then
     83writes a text file describing the names and addresses of those functions
     84to the profiling-session directory created above.  (The naming conventions
     85for and format of that file are described in
    91 ? (CHUD:METER (fact-n-m-times 1000 1000))
    93 The first time that CHUD:METER is invoked in a lisp session, it'll:
     893) run the shark program ("/usr/bin/shark") and wait until it's ready to
     90receive signals that control its operation.
    95 1. Ensure that Shark is running
     92This startup activity typically takes a few seconds; after it's been
     93completed, subsequent use of CHUD:METER doesn't involve that overhead.
     94(See the discussion of :RESET below.)
    97 2. Move the code vectors of all functions to a static
    98    memory area.
     96After any startup activity is complete, CHUD:METER arranges to send
     97a "start profiling" signal to the running shark program, executes
     98the form, sends a "stop profiling" signal to the shark program, and
     99reads its diagnostic output, looking for the name of the ".mshark"
     100file it produces.  If it's able to find this filename, it arranges
     101for "" to open it
    100 3. Write a Shark "spatch" file to the user's home
    101    directory (which is where we configure Shark to look
    102    for such files back in the "Prerequisites" section.)
    103    See also CHUD:*SPATCH-DIRECTORY-PATH*.
     103Profiling "configurations".
    105 4. Try to ensure that Shark is running in "remote" mode.
    106    (I don't know of any way in which this can be ensured
    107    programatically, so it'll just keep asking whether or
    108    not Shark's in remote mode until you say "y" and the
    109    lisp metering code detects that that's the case.)
     106By default, a shark profiling session will:
     107a) use "time based" sampling, to periodically interrupt the lisp
     108   process and note the value of the program counter and at least
     109   a few levels of call history.
     110b) do this sampling once every millisecond
     111c) run for up to 30 seconds, unless told to stop earlier.
    111 Those steps may take anywhere from "a few" to "several" seconds; steps
    112 2 and 3 are probably the most expensive and depend on how many
    113 functions are in the lisp image, how big they are, etc.
     113This is known as "the default configuration"; it's possible to use
     114items on the "Config" menu in the Shark application to create alternate
     115configurations which provide different kinds of profiling parameters
     116and to save these configurations in files for subsequent reuse.
     117(The set of things that CHUD knows how to monitor is large and interesting.)
    115 On every invocation of CHUD:METER, it'll tell Shark to start a
    116 metering session, execute the form which is its required argument,
    117 tell Shark to stop the session, and return the form's result(s).
     119You use alternate profiling configurations (created and "exported" via with CHUD:METER, but the interface is a little awkward.
    119 After it's been told to stop the sampling session, Shark will analyze
    120 the sampling data it obtained and display the results. In this
    121 example, it's reasonable to assume that some CCL package functions
    122 related to bignum multiplication dominate the execution time. Lisp
    123 functions that show up in Shark's session window will claim to be
    124 defined in the SPATCH library; their "names" will generally look like
    125 their printed representations.
    127  Limitations
     125CHUD:*SHARK-CONFIG-FILE*   [Variable]
    129 It's generally tempting to start redefining functions that have
    130 longer-than-expected execution times. That's possibly the right thing
    131 to do in general, but (because of the way that the spatch mechanism
    132 works) it's hard to get meaningful results: Shark can only give names
    133 to lisp functions that're in its .spatch file, and will continue to
    134 use cached informaton from that .spatch file until it quits. General
    135 (GC-able) lisp functions - whose code-vectors might move around in
    136 memory - tend to confuse Shark (and at least some versions get
    137 confused enough that they may crash while trying to report time spent
    138 in functions that aren't where they used to be ...)
     127When non-null, this should be the pathname of an alternate profiling
     128configuration file created by the "Config Editor" in
    140 After things get a little bit out-of-whack (in terms of newly defined
    141 lisp functions), it's often necessary to quit both Shark and OpenMCL,
    142 load the new-and-improved code into the lisp, and try again, hoping
    143 for better results.
     130(CHUD:METER form &key (reset nil) (debug-output nil))  [Macro]
    145 After CHUD:METER has done its first-time setup, it's generally
    146 necessary to quit both Shark and OpenMCL if either quits in order to
    147 get them back in synch again.
     132Executes FORM (an arbitrary lisp form) and returns whatever result(s)
     133it returns, with CHUD profiling enabled during the form's execution.
     134Tries to determine the name of the session file (*.mshark) to which
     135the shark program wrote profiling data and opens this file in the
     136Shark application.
    149 Despite these limitations, it's probably fair to say that this is way,
    150 way better than nothing.
    152  Reference
     140debug-output   - when non-nil, causes output generated by the shark program to
     141                 be echoed to *TERMINAL-IO*.  For debugging.
     142reset          - when non-nil, terminates any running instance of the
     143                 shark program created by previous invocations of CHUD:METER
     144                 in this lisp session, generates a new .spatch file
     145                 (describing the names and addresses of lisp functions),
     146                 and starts a new instance of the shark program; if
     147                 CHUD:*SHARK-CONFIG-FILE* is non-NIL when this new instance
     148                 is started, that instance is told to use the specified
     149                 config file for profiling (in lieu of the default profiling
     150                 configuration.)
    154 (CHUD:METER form &key (duration 0) (frequency 1))  [Macro]
    156 Ensures that access to the "remote sampling facility" (Shark, usually)
    157 has been acquired, ensure that code vectors have been purified and
    158 that an spatch file for the current process is writen to the directory
    159 named by CHUD:*SPATCH-DIRECTORY-PATH* (or the user's home directory),
    160 and starts and stops the sampling facility around execution of <form>.
    161 Returns whatever values execution of <form> returns.
    163 Arguments
    164   <form>        an arbitrary lisp expression
    165   <frequency>   sampling frequency in milliseconds
    166   <duration>    total number of sampling intervals, 0 implies "infinite".
    168 It seems that the <frequency> and <duration> arguments have no effect;
    169 the sampling frequency and duration can be set via Shark's "configuration
    170 editor" dialog.
    172 CHUD:*SPATCH-DIRECTORY-PATH*  [Special Variable]
    174 If non-NIL, should be a pathname whose directory component matches the
    175 "Patch FIles" search path in Shark's Preferences.  When this variable
    176 is NIL, USER-HOMEDIR-PATHNAME is used instead.
    179  Acknowledgments
    181155Both Dan Knapp and Hamilton Link have posted similar CHUD interfaces
Note: See TracChangeset for help on using the changeset viewer.