Changeset 9204 for release/1.2

Apr 20, 2008, 9:06:25 AM (14 years ago)

from trunk

1 edited


  • release/1.2/source/library/oprofile.txt

    r9200 r9204  
    1 This needs to be written.
     1Using the Linux oprofile system-level profiler with CCL
     4'oprofile' (<>) is a system-level profiler
     5that's available for most modern Linux distributions.
     7Use of oprofile and its companion programs isn't really documented here;
     8what -is- described is a way of generating symbolic information that
     9enables profiling summaries generated by the 'opreport' program to
     10identify lisp functions meaningfully.
     13Generating a lisp image for use with oprofile
     16Modern Linux uses the 'ELF" (Executable and Linking Format) object
     17file format; the oprofile tools can associate symbolic names with
     18addresses in a memory-mapped file if that file appears to be an
     19ELF object file and if it contains ELF symbol information that
     20describes those memory regiions.  So, the general idea is to make
     21a lisp heap image that looks enough like an ELF shared library
     22to fool the oprofile tools (we don't actually load heap images
     23via ELF dynamic linking technology, but we can make it look like
     24we did.)
     291) oprofile itself, which is almost certainly available via your
     30distributions's package management system if not already preinstalled.
     312) 'libelf', which provides utilities for reading and writing ELF
     32files (and is likewise likely preinstalled or readily installable.)
     34Generating ELF symbols for lisp functions.
     36In order to create a lisp heap image which can be used for oprofile-
     37based profiling, we need to:
     391) load any code that we want to profile
     402) generate a file that contains ELF symbol information describing
     41the names and addresses of all lisp functions.
     43This step involves doing (from within CCL)
     45? (require "ELF")
     49? (ccl::write-elf-symbols-to-file "home:elf-symbols")
     51The argument to CCL::WRITE-ELF-SYMBOLS-TO-FILE can be any writable
     52pathname.  The function will do whatever's necessary to nail lisp
     53functions down in memory (so that they aren't moved by GC), then
     54write an ELF object file to the indicated pathname.  This typically
     55takes a few seconds.
     573) Generating a lisp heap image in which the ELF symbols generated
     58in the previous step are prepended.
     60The function CCL:SAVE-APPLICATION provides a :PREPEND-KERNEL argument,
     61which is ordinarily used to save a standalone application in which
     62the kernel and heap image occupy a single file.  :PREPEND-KERNEL
     63doesn't really care what it's prepending to the image, and we can
     64just as easily ask it to prepend the ELF symbol file generated in
     65the previous step.
     67? (save-application "somewhere/image-for-profiling" :prepend-kernel
     70If you then run
     72shell> ccl64 somewhare/image-for-profiling
     74any lisp code sampled by oprofile in that image will be identified
     75"symbolically" by opreport.
     79;;; Define some lisp functions that we want to profile and save
     80;;; a profiling-enabled image.  In this case, we just want to
     81;;; define the FACTORIAL funcion, to keep things simple.
     82? (defun fact (n) (if (zerop n) 1 (* n (fact (1- n)))))
     84? (require "ELF")
     87? (ccl::write-elf-symbols-to-file "home:elf-symbols")
     89? (save-application "home:profiled-ccl" :prepend-kernel "home:elf-symbols")
     91;;; Setup oprofile with (mostly) default arguments.  This example was
     92;;; run on a Fedora 8 system where an uncompressed 'vmlinux' kernel
     93;;; image isn't readily available.
     95;;; Note that use of 'opcontrol' generally requires root access, e.g.,
     96;;; 'sudo' or equivalent:
     98[~] gb@rinpoche> sudo opcontrol --no-vmlinux --setup
     100;;; Start the profiler
     102[~] gb@rinpoche> sudo opcontrol --start
     103Using 2.6+ OProfile kernel interface.
     104Using log file /var/lib/oprofile/samples/oprofiled.log
     105Daemon started.
     106Profiler running.
     108;;; Start CCL with the "profiled-ccl" image created above.
     109;;; Invoke "(FACT 10000)"
     111[~] gb@rinpoche> ccl64 profiled-ccl
     112Welcome to Clozure Common Lisp Version 1.2-r9198M-trunk  (LinuxX8664)!
     113? (null (fact 10000))
     115? (quit)
     117;;; We could stop the profiler (opcontrol --stop) here; instead,
     118;;; we simply flush profiling data to disk, where 'opreport' can
     119;;; find it.
     121[~] gb@rinpoche> sudo opcontrol --dump
     123;;; Ask opreport to show us where we were spending time in the
     124;;; 'profiled-ccl' image.
     126[~] gb@rinpoche> opreport -l profiled-ccl | head
     127CPU: Core 2, speed 1596 MHz (estimated)
     128Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (Unhalted core cycles) count 100000
     129samples  %        symbol name
     1306417     65.2466  <Compiled-function.(:INTERNAL.MULTIPLY-UNSIGNED-BIGNUM-AND-1-DIGIT-FIXNUM.MULTIPLY-BIGNUM-AND-FIXNUM).(Non-Global)..0x30004002453F>
     1313211     32.6487  <Compiled-function.%MULTIPLY-AND-ADD4.0x300040000AAF>
     13217        0.1729  <Compiled-function.%%ONE-ARG-DCODE.0x3000401740AF>
     13311        0.1118  <Compiled-function.%UNLOCK-RECURSIVE-LOCK-OBJECT.0x30004007F7DF>
     13410        0.1017  <Compiled-function.AUTO-FLUSH-INTERACTIVE-STREAMS.0x3000404ED6AF>
     1357         0.0712  <Compiled-function.%NANOSLEEP.0x30004040385F>
     1367         0.0712  <Compiled-function.%ZERO-TRAILING-SIGN-DIGITS.0x300040030F3F>
     138I think that we can conclude that (FACT 10000) mostly involves multiplying
     139bignums by small fixnums.
     143CCL::WRITE-ELF-SYMBOLS-TO-FILE currently only works on x86-64; it certainly
     144-could- be made to work on ppc32/ppc64 as well.
     146So far, no one has been able to make oprofile/opreport options that're
     147supposed to generate call-stack info generate meaningful call-stack info.
     149As of a few months ago, there was an attempt to provide symbol info
     150for oprofile/opreport "on the fly", e.g., for use in JIT compilation
     151or other incremental compilations scenarios.  That's obviously more nearly
     152The Right Thing, but it might be awhile before that experimental code
     153makes it into widespread use.
Note: See TracChangeset for help on using the changeset viewer.