1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950515253545556575859606162636465666768697071727374757677787980818283848586878889909192939495969798991001011021031041051061071081091101111121131141151161171181191201211221231241251261271281291301311321331341351361371381391401411421431441451461471481491501511521531541551561571581591601611621631641651661671681691701711721731741751761771781791801811821831841851861871881891901911921931941951961971981992002012022032042052062072082092102112122132142152162172182192202212222232242252262272282292302312322332342352362372382392402412422432442452462472482492502512522532542552562572582592602612622632642652662672682692702712722732742752762772782792802812822832842852862872882892902912922932942952962972982993003013023033043053063073083093103113123133143153163173183193203213223233243253263273283293303313323333343353363373383393403413423433443453463473483493503513523533543553563573583593603613623633643653663673683693703713723733743753763773783793803813823833843853863873883893903913923933943953963973983994004014024034044054064074084094104114124134144154164174184194204214224234244254264274284294304314324334344354364374384394404414424434444454464474484494504514524534544554564574584594604614624634644654664674684694704714724734744754764774784794804814824834844854864874884894904914924934944954964974984995005015025035045055065075085095105115125135145155165175185195205215225235245255265275285295305315325335345355365375385395405415425435445455465475485495505515525535545555565575585595605615625635645655665675685695705715725735745755765775785795805815825835845855865875885895905915925935945955965975985996006016026036046056066076086096106116126136146156166176186196206216226236246256266276286296306316326336346356366376386396406416426436446456466476486496506516526536546556566576586596606616626636646656666676686696706716726736746756766776786796806816826836846856866876886896906916926936946956966976986997007017027037047057067077087097107117127137147157167177187197207217227237247257267277287297307317327337347357367377387397407417427437447457467477487497507517527537547557567577587597607617627637647657667677687697707717727737747757767777787797807817827837847857867877887897907917927937947957967977987998008018028038048058068078088098108118128138148158168178188198208218228238248258268278288298308318328338348358368378388398408418428438448458468478488498508518528538548558568578588598608618628638648658668678688698708718728738748758768778788798808818828838848858868878888898908918928938948958968978988999009019029039049059069079089099109119129139149159169179189199209219229239249259269279289299309319329339349359369379389399409419429439449459469479489499509519529539549559569579589599609619629639649659669679689699709719729739749759769779789799809819829839849859869879889899909919929939949959969979989991000100110021003100410051006100710081009101010111012101310141015101610171018101910201021102210231024102510261027102810291030103110321033103410351036103710381039104010411042104310441045104610471048104910501051105210531054105510561057105810591060106110621063106410651066106710681069107010711072107310741075107610771078107910801081108210831084108510861087108810891090109110921093109410951096109710981099110011011102110311041105110611071108110911101111111211131114111511161117111811191120112111221123112411251126112711281129113011311132113311341135113611371138113911401141114211431144114511461147114811491150115111521153115411551156115711581159116011611162116311641165116611671168116911701171117211731174117511761177117811791180118111821183118411851186118711881189119011911192119311941195119611971198119912001201120212031204120512061207120812091210121112121213121412151216121712181219122012211222122312241225122612271228122912301231123212331234123512361237123812391240124112421243124412451246124712481249125012511252125312541255125612571258125912601261126212631264126512661267126812691270127112721273127412751276127712781279128012811282128312841285128612871288128912901291129212931294129512961297129812991300130113021303130413051306130713081309131013111312131313141315131613171318131913201321132213231324132513261327132813291330133113321333133413351336133713381339134013411342134313441345134613471348134913501351135213531354135513561357135813591360136113621363136413651366136713681369137013711372137313741375137613771378137913801381138213831384138513861387138813891390139113921393139413951396139713981399140014011402140314041405140614071408140914101411141214131414141514161417141814191420142114221423142414251426142714281429143014311432143314341435143614371438143914401441144214431444144514461447144814491450145114521453145414551456145714581459146014611462146314641465146614671468146914701471147214731474147514761477147814791480148114821483148414851486148714881489149014911492149314941495149614971498149915001501150215031504150515061507150815091510151115121513151415151516151715181519152015211522152315241525152615271528152915301531153215331534153515361537153815391540154115421543154415451546154715481549155015511552155315541555155615571558155915601561156215631564156515661567156815691570157115721573157415751576157715781579158015811582158315841585158615871588158915901591159215931594159515961597159815991600160116021603160416051606160716081609161016111612161316141615161616171618161916201621162216231624162516261627162816291630163116321633163416351636163716381639164016411642164316441645164616471648164916501651165216531654165516561657165816591660166116621663166416651666166716681669167016711672167316741675167616771678167916801681168216831684168516861687168816891690169116921693169416951696169716981699170017011702170317041705170617071708170917101711171217131714171517161717171817191720172117221723172417251726172717281729173017311732 |
- ; Copyright (c) 1993-2008 by Richard Kelsey and Jonathan Rees. See file COPYING.
- ;;;;;; Rudimentary Scheme48 profiler -*- Scheme -*-
- ;;; Taylor Campbell wrote parts of the original code; he has placed them in the public domain.
- ;; profiling information for each template
- (define-record-type profinfo :profinfo
- (really-make-profinfo template callers occurs hist memoryuse min-pc instrumented cycle)
- profinfo?
- (template profinfo-template) ; scheme code template
- (callers profinfo-callers profinfo-set-callers!) ; table of callerinfos
- (occurs profinfo-occurs profinfo-set-occurs!)
- (hist profinfo-hist profinfo-set-hist!)
- (tchild profinfo-tchild profinfo-set-tchild!)
- (toporder profinfo-toporder profinfo-set-toporder!)
- (dfn profinfo-dfn profinfo-set-dfn!) ; depth-first number
- (cycle profinfo-cycle profinfo-set-cycle!)
- (memoryuse profinfo-memoryuse profinfo-set-memoryuse!)
- (min-pc profinfo-min-pc profinfo-set-min-pc!)
- (instrumented profinfo-instrumented? profinfo-set-instrumented?!))
- (define (make-profinfo prof-data template)
- (let ((pi (really-make-profinfo template
- (make-table profinfo-id)
- 0 0 0 #f #f #f)))
- (table-set! (profile-data-templates prof-data) template pi)
- pi))
- ;; profiling data for template when being called by CALLER
- (define-record-type callerinfo :callerinfo
- (make-callerinfo caller calls)
- callerinfo?
- (caller callerinfo-caller) ; caller profinfo
- (calls callerinfo-calls callerinfo-set-calls!) ; number of calls
- (tself callerinfo-tself callerinfo-set-tself!) ; time spent in called self
- (tchild callerinfo-tchild callerinfo-set-tchild!)) ; time spent in children of called
- ;;; Miscellaneous global stuff
- (define-record-type profile-data :profile-data
- (really-make-profile-data)
- (interrupttime profile-data-interrupttime set-profile-data-interrupttime!)
- (measure-noninstr? profile-data-measure-noninstr? set-profile-data-measure-noninstr?!)
- (starttime profile-data-starttime set-profile-data-starttime!)
- (endtime profile-data-endtime set-profile-data-endtime!)
- (root profile-data-root set-profile-data-root!)
- (cycles profile-data-cycles set-profile-data-cycles!)
- (samples profile-data-samples set-profile-data-samples!)
- (templates profile-data-templates set-profile-data-templates!)
- (memoryuse profile-data-memoryuse set-profile-data-memoryuse!)
- (gcruns profile-data-gcruns set-profile-data-gcruns!))
- ;; hash function for callers table in profiling information
- (define (profinfo-id pi)
- ; (template-id (profinfo-template pi)))
- 0)
- (define (make-empty-profile-data)
- (let ((pd (really-make-profile-data)))
- (set-profile-data-interrupttime! pd (profiler-default-interrupt-time))
- (set-profile-data-measure-noninstr?! pd (profiler-measure-non-instrumented?))
- (set-profile-data-memoryuse! pd 0)
- (set-profile-data-cycles! pd '())
- pd))
- (define-record-type cycleinfo :cycleinfo
- (make-cycleinfo number members)
- cycleinfo?
- (number cycleinfo-number) ; consecutive numbering
- (members cycleinfo-members cycleinfo-set-members!) ; member profinfos
- (tchild cycleinfo-tchild cycleinfo-set-tchild!)
- )
- ;; represents a stack entry (while profiling)
- (define-record-type stackentry :stackentry
- (really-make-stackentry cont template calls firstseen seen)
- stackentry?
- (cont stackentry-cont stackentry-set-cont!) ; scheme continuation
- (template stackentry-template stackentry-set-template!) ; scheme code template
- (calls stackentry-reccalls stackentry-set-reccalls!) ; recursive calls
- (firstseen stackentry-firstseen stackentry-set-firstseen!) ; run-time first seen this entry
- (seen stackentry-seen stackentry-set-seen!)) ; seen this time? (boolean)
- (define (make-stackentry cont template)
- (really-make-stackentry cont template 0 (run-time) #f))
- ;;; Global profiling stuff (independent of prof-data)
- (define *interrupt-time* #f) ; (theoretical) ms between interrupts
- (define *measure-noninstr?* #f)
- (define *saved-interrupt-handler* #f) ; non-profiler interrupt handler
- (define *profiler-continuation* #f) ; profiler's top continuation
- (define *profiler-lock* (make-lock)) ; exclusive lock for interrupt handler
- (define *profiler-lastrun* #f) ; run-time of profiler runs
- (define *profiler-thisrun* #f)
- (define *start-gc-count* 0)
- (define *last-gc-count* 0)
- (define *cur-gc-count* 0)
- (define *last-avail-memory* 0)
- (define *cur-avail-memory* 0)
- (define interrupt/alarm (enum interrupt alarm))
- (define *active-profile-data* #f)
- (define *first-call?* #f)
- ;;; Sampling interrupt time (with setting)
- (define *profiler-default-interrupt-time* 50)
- (define (positive-integer? n)
- (and (integer? n)
- (exact? n)
- (positive? n)))
- (define (profiler-default-interrupt-time)
- *profiler-default-interrupt-time*)
- (define (set-profiler-default-interrupt-time! interrupt-time)
- (set! *profiler-default-interrupt-time* interrupt-time))
- (add-setting 'profiler-interrupt-time positive-integer?
- profiler-default-interrupt-time
- set-profiler-default-interrupt-time!
- "profiler sampling interrupt time in milliseconds")
- ;;; Measure-non-instrumented? flag
- (define *profiler-measure-non-instrumented?* #t)
- (define (profiler-measure-non-instrumented?)
- *profiler-measure-non-instrumented?*)
- (define (set-profiler-measure-non-instrumented?! do?)
- (set! *profiler-measure-non-instrumented?* do?))
- (add-setting 'profiler-measure-noninstr #t
- profiler-measure-non-instrumented?
- set-profiler-measure-non-instrumented?!
- "profiler will measure calls to non-instrumented code"
- "profiler will only measure calls to instrumented code")
- ;;; Miscellaneous global stuff
- (define (run-time)
- (primitives:time (enum time-option run-time) #f))
- ;; debug display
- (define (ddisplay x)
- ; (display x)
- #f)
- (define (get-profinfo prof-data stack-entry)
- (if stack-entry
- (get-profinfo-from-template prof-data (stackentry-template stack-entry))
- #f))
- (define (profiler-continuation? cont)
- (eq? cont *profiler-continuation*))
- (define (get-profinfo-from-template prof-data template)
- (or (table-ref (profile-data-templates prof-data) template)
- (make-profinfo prof-data template)))
- (define (get-profinfo prof-data stack-entry)
- (if stack-entry
- (get-profinfo-from-template prof-data (stackentry-template stack-entry))
- #f))
- (define (get-template-name-and-modules prof-data template)
- (if (eq? template (profile-data-root prof-data))
- (cons '<profiler> '())
- (let ((ddata (template-debug-data template)))
- (if (not (and (debug-data? ddata)
- (pair? (debug-data-names ddata))))
- (cons (string-append "anonymous"
- (if (debug-data? ddata)
- (number->string (debug-data-uid ddata))
- (if (number? ddata)
- (number->string ddata)
- "?")))
- '())
- (let loop ((names (debug-data-names ddata))
- (lst '()))
- (set! lst (cons (or (car names) "anonymous") lst))
- (if (pair? (cdr names))
- (loop (cdr names) lst)
- (reverse lst)))))))
- (define (same-name? a b)
- (string=? (if (symbol? a)
- (symbol->string a)
- a)
- (if (symbol? b)
- (symbol->string b)
- b)))
- (define (profile-data-find prof-data names)
- (let ((found-lst '()))
- (table-walk
- (lambda (template pi)
- (let loop ((names names)
- (tempnames (get-template-name-and-modules prof-data template)))
- (if (string? names)
- ;; only string given, search match in path
- (if (pair? tempnames)
- (if (same-name? names (car tempnames))
- (set! found-lst (cons pi found-lst))
- (loop names (cdr tempnames))))
- ;; list of strings given, requires full path matching
- (if (not (pair? names))
- (set! found-lst (cons pi found-lst))
- (if (and (pair? tempnames)
- (same-name? (car names) (car tempnames)))
- (loop (cdr names) (cdr tempnames)))))))
- (profile-data-templates prof-data))
- found-lst))
- (define (do-for-first-matching fun prof-data names)
- (let ((pis (profile-data-find prof-data names)))
- (if (pair? pis)
- (fun (car pis)))))
- ;;; MAIN
- (define (profile command . interrupt-time)
- (profile-and-display (if (eq? (car command) 'run)
- (eval `(LAMBDA () ,(cadr command))
- (environment-for-commands))
- (lambda () (execute-command command)))
- interrupt-time
- (current-output-port)))
- (define (profile-and-display thunk
- interrupt-time
- port)
- (let ((prof-data (make-empty-profile-data)))
- (call-with-values
- (lambda ()
- (if (null? interrupt-time)
- (profile-thunk prof-data thunk)
- (profile-thunk prof-data thunk (car interrupt-time))))
- (lambda results
- (profile-display prof-data port)
- (set-command-results! results)))))
- (define (profile-thunk prof-data thunk . opt-args)
- (if (not (eq? (profile-data-samples prof-data)
- (primitives:unspecific)))
- (error 'profile-thunk
- "a profile-data record can be used only once"))
- (set! *interrupt-time* #f)
- (set! *measure-noninstr?* (primitives:unspecific))
-
- ;; optional arguments: interrupt-time ...
- (case (length opt-args)
- ((1) ; interrupt time
- (let ((int-time (car opt-args)))
- (set! *interrupt-time* int-time)))
- ((2) ; interrupt time with non-instr?
- (let ((int-time (car opt-args))
- (non-instr? (cadr opt-args)))
- (set! *interrupt-time* int-time)
- (set! *measure-noninstr?* non-instr?)))
- )
-
- ;; profile-data interrupt time, if not set
- (if (not *interrupt-time*)
- (set! *interrupt-time* (profile-data-interrupttime prof-data)))
- ;; profile-data measure-noninstr?, if not set
- (if (eq? *measure-noninstr?* (primitives:unspecific))
- (set! *measure-noninstr?* (profile-data-measure-noninstr? prof-data)))
-
- (if *profiler-continuation*
- (error
- 'profile-thunk
- "profiler can not be running twice at the same time" thunk)
- (begin
- (set! *active-profile-data* prof-data)
- (set! *first-call?* #t)
- (set! *last-stack* #f)
- (set! *profiler-thisrun* #f)
- (set! *profiler-lastrun* #f)
- (set! *last-avail-memory* (available-memory))
- (set! *start-gc-count* (get-current-gc-count))
- (set! *last-gc-count* *start-gc-count*)
- (release-lock *profiler-lock*)
- ;; init profile-data
- (set-profile-data-templates! prof-data (make-table template-id))
- (set-profile-data-samples! prof-data 0)
- (set-profile-data-starttime! prof-data (run-time))
- (set-profile-data-interrupttime! prof-data *interrupt-time*)
-
- ;; this is more flexible than generating a own template
- (primitive-cwcc
- (lambda (cont)
- (set-profile-data-root! prof-data
- (continuation-template cont))))
-
- (call-with-values
- (lambda ()
- (dynamic-wind
- (lambda ()
- (install-profiler-interrupt-handler)
- (start-periodic-interrupts!))
- (lambda ()
- (primitive-cwcc
- (lambda (profiler-cont)
- (set! *profiler-continuation* profiler-cont)
- (thunk)))) ; run program!
- (lambda ()
- (set! *profiler-continuation* #f)
- (stop-periodic-interrupts!)
- (uninstall-profiler-interrupt-handler)
-
- (set-profile-data-endtime! prof-data (run-time))
- (set-profile-data-gcruns! prof-data (- (get-current-gc-count) *start-gc-count*))
-
- (post-process-stack! prof-data *last-stack*) ; process the last stack trace
-
- ;; do necessary calculations
- (remove-uncalled prof-data)
- (depth-numbering prof-data)
- (propagate-times prof-data)
- (toporder-numbering prof-data)
-
- (set! *active-profile-data* #f))))
- (lambda results
- (apply values results))))))
- ;;; INTERRUPT HANDLING
- (define (start-periodic-interrupts!)
- (schedule-interrupt *interrupt-time*))
- (define (stop-periodic-interrupts!)
- (schedule-interrupt 0))
- (define (install-profiler-interrupt-handler)
- (set! *saved-interrupt-handler* (get-interrupt-handler interrupt/alarm))
- (set-interrupt-handler! interrupt/alarm handle-profiler-interrupt))
- (define (uninstall-profiler-interrupt-handler)
- (let ((handler *saved-interrupt-handler*))
- (set! *saved-interrupt-handler* #f)
- (set-interrupt-handler! interrupt/alarm handler)))
- (define (handle-profiler-interrupt template enabled)
- ;; After Scheme48 1.0's architectural changes TEMPLATE argument has
- ;; always been just #f.
- ;; first thing is getting the continuation, in tail position to prevent
- ;; capturing profiler functions
- (primitive-cwcc
- (lambda (cont)
- (if (maybe-obtain-lock *profiler-lock*)
- (begin
- (*saved-interrupt-handler* template enabled) ; thread system, ...
- (if *profiler-continuation* (record-continuation! *active-profile-data* cont))
- (release-lock *profiler-lock*)
- ;; HACK: To override thread system interrupt scheduling, may cause
- ;; extreme performance loss on thread system?
- (start-periodic-interrupts!))))))
- ;;; DISPLAY DATA
- ;; display s right-aligned in field with width w
- (define (display-w s w port)
- (if (< (string-length s) w)
- (begin
- (display " " port)
- (display-w s (- w 1) port))
- (display s port)))
- ;; display number right-aligned in field with width w
- (define (display-w-nr n w port)
- (if n
- (display-w (number->string (round n)) w port)
- (display-w "?" w port)))
- ;; same as above, but do not display 0 values
- (define (display-w-nr-nz n w port)
- (if (= n 0)
- (display-w "" w port)
- (display-w-nr n w port)))
- (define (display-w-mem n w port)
- (if (> n 1000000000)
- (display-w (string-append (number->string (round (/ n 1000000))) "M") w port)
- (display-w (string-append (number->string (round (/ n 1000))) "k") w port)))
- (define (display-sep-nrs nr1 nr2 sep w port)
- (display-w
- (string-append (number->string nr1) sep (number->string nr2))
- w
- port))
- (define (display-sep-unequal-nrs nr1 nr2 sep w port)
- (display-w
- (if (= nr1 nr2)
- (number->string nr1)
- (string-append (number->string nr1) sep (number->string nr2)))
- w
- port))
- (define (display-sep-nz-nrs nr1 nr2 sep w port)
- (display-w
- (if (> nr2 0)
- (string-append (number->string nr1) sep (number->string nr2))
- (number->string nr1))
- w
- port))
- ;; Are there no functions for this!?
- (define (number-as-percent-string nr)
- (if nr
- (let* ((expanded (truncate (* 10000 nr)))
- (afterdot (round (inexact->exact (modulo expanded 100))))
- (full (round (inexact->exact (quotient (- expanded afterdot) 100)))))
- (string-append (number->string full)
- "."
- (number->string afterdot)
- "%"))
- "?"))
- (define (save/ a b)
- (if (= b 0)
- #f
- (/ a b)))
- (define (parse-port-arg opt-port)
- (if (null? opt-port)
- (current-output-port)
- (car opt-port)))
- (define (has-samples prof-data)
- (> (profile-data-samples prof-data) 0))
- (define (profile-display prof-data . opt-port)
- (let ((port (parse-port-arg opt-port)))
- (profile-display-overview prof-data port)
- (newline port)
- (profile-display-flat prof-data port)
- (newline port)
- (profile-display-tree prof-data port)))
- ;; general profiling data
- (define (profile-display-overview prof-data . opt-port)
- (let ((port (parse-port-arg opt-port))
- (run-time (profile-data-runtime prof-data))
- (samples (profile-data-samples prof-data)))
-
- (display "** Samples: " port)
- (display samples port)
- (if (has-samples prof-data)
- (begin
- (display " (approx. one per " port)
- (display (round (/ run-time samples)) port)
- (display "ms)")))
- (newline port)
- (display "** Interrupt time: " port)
- (display *interrupt-time* port)
- (display "ms" port)
- (newline port)
-
- (display "** Real run time: " port)
- (display run-time port)
- (display "ms" port)
- (newline port)
-
- (if (has-samples prof-data)
- (begin
- (display "** Total memory: " port)
- (display (round (/ (profile-data-memoryuse prof-data) 1000)) port)
- (display "k" port)
- (newline port)
-
- (display "** GC runs: " port)
- (display (profile-data-gcruns prof-data) port)
- (newline port)))))
- (define (profile-display-flat prof-data . opt-port)
- (let ((port (parse-port-arg opt-port)))
-
- (display "** Flat result (times in ms):" port)
- (newline port)
- (newline port)
-
- ;; gprof:
- ;; % cumulative self self total
- ;; time seconds seconds calls ms/call ms/call name
-
- (if (has-samples prof-data)
- (begin
- (display-w "time" 7 port)
- (display-w "cumu" 7 port)
- (display-w "self" 7 port)
- (display-w "mem" 10 port)))
- (display-w "calls" 14 port)
- (display-w "ms/call" 9 port)
- (display-w "name" 7 port)
- (newline port)
- ;; sort and print
- (let ((sorted-templates
- (get-sorted-templates prof-data (lambda (pi) (- (profinfo-hist pi))) #t)))
- (for-each (lambda (profinfo)
- (profile-display-profinfo-flat prof-data profinfo port))
- sorted-templates))))
- ;; display data "gprof call graph"-like
- (define (profile-display-tree prof-data . opt-port)
- (let ((port (parse-port-arg opt-port))
- (cycles (profile-data-cycles prof-data)))
-
- (display "** Tree result (times in ms):" port)
- (newline port)
- (newline port)
-
- (display-w "i" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "time" 8 port)
- (display-w "self" 7 port)
- (display-w "child" 7 port)
- (display-w "mem" 10 port)))
- (display-w "calls" 14 port)
- (display-w "name" 7 port)
- (newline port)
-
- ;; sort and print
- (let ((sorted-templates
- (get-sorted-templates prof-data (lambda (pi) (- (profinfo-occurs pi))) #t)))
- (for-each (lambda (profinfo)
- (profile-display-profinfo-tree prof-data profinfo port))
- sorted-templates))
- (if cycles
- (for-each (lambda (cyc)
- (profile-display-cycle-tree prof-data cyc port))
- cycles))))
- (define (profile-function-calls prof-data names)
- (do-for-first-matching profinfo-total-calls prof-data names))
- (define (profile-function-reccalls prof-data names)
- (do-for-first-matching profinfo-total-reccalls prof-data names))
- (define (profile-function-nonreccalls prof-data names)
- (do-for-first-matching profinfo-total-nonreccalls prof-data names))
- (define (profile-function-occurs prof-data names)
- (do-for-first-matching profinfo-occurs prof-data names))
- (define (profile-function-hist prof-data names)
- (do-for-first-matching profinfo-hist prof-data names))
- (define (profile-function-memoryuse prof-data names)
- (do-for-first-matching profinfo-memoryuse prof-data names))
- (define (profile-function-timeshare prof-data names)
- (do-for-first-matching (lambda (pi) (profinfo-timeshare prof-data pi)) prof-data names))
- (define (profile-function-time-cumulative prof-data names)
- (do-for-first-matching (lambda (pi) (profinfo-total-ms prof-data pi)) prof-data names))
- (define (profile-function-time-self prof-data names)
- (do-for-first-matching (lambda (pi) (profinfo-self-ms prof-data pi)) prof-data names))
- (define (profile-display-function-flat prof-data names . opt-port)
- (let ((port (parse-port-arg opt-port))
- (pis (profile-data-find prof-data names)))
- (for-each (lambda (pi)
- (profile-display-profinfo-flat prof-data pi port))
- pis)))
- (define (profile-display-profinfo-flat prof-data profinfo port)
- (let* ((template (profinfo-template profinfo))
- (occurs (profinfo-occurs profinfo))
- (calls (profinfo-total-calls profinfo))
- (reccalls (profinfo-total-reccalls profinfo))
- (nonreccalls (profinfo-total-nonreccalls profinfo))
- (hist (profinfo-hist profinfo))
- (memuse (profinfo-memoryuse profinfo))
- (timeshare (profinfo-timeshare prof-data profinfo))
- (ttotal (profinfo-total-ms prof-data profinfo))
- (tself (profinfo-self-ms prof-data profinfo))
- (ms/call (save/ (occurs->ms prof-data occurs) calls)))
- (if (not (eq? template (profile-data-root prof-data)))
- (begin
-
- (if (has-samples prof-data)
- (begin
- (display-w (number-as-percent-string timeshare) 7 port)
- (display-w-nr ttotal 7 port)
- (display-w-nr tself 7 port)
- (display-w-mem memuse 10 port)))
- (display-sep-nz-nrs nonreccalls reccalls "+" 14 port)
- (display-w-nr ms/call 9 port)
-
- (display " " port)
- (display-location prof-data template port) ; name
- (newline port)
- ))))
- (define (profile-display-function-cycle prof-data names . opt-port)
- (let ((port (parse-port-arg opt-port))
- (pis (profile-data-find prof-data names)))
- (for-each (lambda (pi)
- (let ((ci (profinfo-cycle pi)))
- (if ci
- (profile-display-cycle-tree prof-data ci port))))
- pis)))
- (define (profile-display-cycle-tree prof-data cycleinfo port)
- (let* ((number (cycleinfo-number cycleinfo))
- (members (cycleinfo-members cycleinfo))
- (callers (cycleinfo-called-from cycleinfo))
- (intcalls (cycleinfo-internal-calls cycleinfo))
- (extcalls (cycleinfo-external-calls cycleinfo))
- (hist (cycleinfo-hist cycleinfo))
- (tchild (cycleinfo-tchild cycleinfo))
- (memuse (cycleinfo-memoryuse cycleinfo))
- (fromextcalls (sumup-calls-int/ext-cycle cycleinfo #f))
- (ttotal (+ hist tchild))
- (timeshare (save/ ttotal (profile-data-samples prof-data))))
- (display "=============================================" port)
- (display "=============================================" port)
- (newline port)
-
- ;; print cycle callers
- (for-each
- (lambda (caller-pi)
- (let* ((calls (cycleinfo-calls-from cycleinfo caller-pi))
- (share (/ calls fromextcalls))
- (tchild (* tchild share))
- (memuse (* memuse share)))
-
- (display-w "" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "" 8 port)
- (display-w-nr (occurs->ms prof-data hist) 7 port)
- (display-w-nr (occurs->ms prof-data tchild) 7 port)
- (display-w-mem memuse 10 port)))
- (display-sep-nz-nrs calls fromextcalls "/" 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data caller-pi port)
- (newline port)))
- callers)
-
-
- ;; print primary line
- (display-w-nr number 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w (number-as-percent-string timeshare) 8 port)
- (display-w-nr (occurs->ms prof-data hist) 7 port)
- (display-w-nr (occurs->ms prof-data tchild) 7 port)
- (display-w-mem memuse 10 port)))
- (display-sep-nz-nrs extcalls intcalls "+" 14 port)
-
- (display " " port)
- (display "<cycle " port)
- (display number port)
- (display " as a whole>" port)
- (newline port)
- ;; print cycle members
- (for-each
- (lambda (member-pi)
- (let* ((intcalls (calls-int/ext-cycle cycleinfo member-pi #t))
- (nonreccalls (profinfo-total-nonreccalls member-pi))
- (totalmemuse (profinfo-memoryuse member-pi))
- (occurs (profinfo-occurs member-pi))
- (hist (profinfo-hist member-pi))
- (tchild (cycleinfo-tchild-member prof-data cycleinfo member-pi))
- (share (/ intcalls nonreccalls))
- (memuse (* totalmemuse share)))
- (display-w "" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "" 8 port)
- (display-w-nr (occurs->ms prof-data hist) 7 port)
- (display-w-nr (occurs->ms prof-data tchild) 7 port)
- (display-w-mem memuse 10 port)))
- (display-w-nr intcalls 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data member-pi port)
- (newline port)))
- members)
-
- ;; print functions called out of the cycle
- (for-each
- (lambda (called-pi)
- (let* ((nonreccalls (profinfo-total-nonreccalls called-pi))
- (totalmemuse (profinfo-memoryuse called-pi))
- (calls (cycleinfo-calls-to cycleinfo called-pi))
- (share (/ calls nonreccalls))
- (memuse (* totalmemuse share)))
- (display-w "" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "" 8 port)
- (display-w-nr 0 7 port)
- (display-w-nr 0 7 port)
- (display-w-mem memuse 10 port)))
- (display-sep-nrs calls nonreccalls "/" 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data called-pi port)
- (newline port)))
- (cycleinfo-called-externals prof-data cycleinfo))))
- (define (profile-display-function-tree prof-data names . opt-port)
- (let ((port (parse-port-arg opt-port))
- (pis (profile-data-find prof-data names)))
- (for-each (lambda (pi)
- (profile-display-profinfo-tree prof-data pi port))
- pis)))
- (define (profile-display-profinfo-tree prof-data primary-pi port)
- (let* ((template (profinfo-template primary-pi))
- (toporder (profinfo-toporder primary-pi))
- (dfn (profinfo-dfn primary-pi))
- (callers (profinfo-callers primary-pi))
- (occurs (profinfo-occurs primary-pi))
- (calls (profinfo-total-calls primary-pi))
- (reccalls (profinfo-total-reccalls primary-pi))
- (nonreccalls (profinfo-total-nonreccalls primary-pi))
- (memuse (profinfo-memoryuse primary-pi))
- (upcalls (profinfo-total-upcalls primary-pi))
- (hist (profinfo-hist primary-pi))
- (tchild (profinfo-tchild primary-pi))
- (primary-cyc (profinfo-cycle primary-pi))
- (timeshare (save/ occurs (profile-data-samples prof-data)))
- (ms/call (save/ (occurs->ms prof-data occurs) calls)))
-
- (display "=============================================" port)
- (display "=============================================" port)
- (newline port)
-
- ;; print parents
- (if (= (table-size callers) 0)
- (if (not (eq? template (profile-data-root prof-data)))
- (begin (display-w " " 49 port) (display " <spontaneous>" port) (newline)))
- (table-walk
- (lambda (caller-pi cinfo)
- (if (not (eq? caller-pi primary-pi))
- (let* ((template (profinfo-template caller-pi))
- (dfn (profinfo-dfn caller-pi))
- (occurs (profinfo-occurs caller-pi))
- (caller-cyc (profinfo-cycle caller-pi))
- (calls (callerinfo-calls cinfo))
- (share (/ calls upcalls))
- (tself-share (* hist share)) ; TODO: correct when recursive function?
- (tchild-share (* tchild share))
- (memuse-share (* memuse share)))
- (display-w "" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "" 8 port)
-
- (if (or (not primary-cyc)
- (not (eq? caller-cyc primary-cyc)))
- (begin
- (display-w-nr (occurs->ms prof-data tself-share) 7 port)
- (display-w-nr (occurs->ms prof-data tchild-share) 7 port)
- (display-w-mem memuse-share 10 port))
- (begin
- (display-w "" 7 port)
- (display-w "" 7 port)
- (display-w "" 10 port)))))
-
- (display-sep-nrs calls nonreccalls "/" 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data caller-pi port)
- (newline port))))
- callers))
- ;; print primary line
- (display-w-nr toporder 3 port)
-
- (if (has-samples prof-data)
- (begin
- (display-w (number-as-percent-string timeshare) 8 port)
- (display-w-nr (occurs->ms prof-data hist) 7 port)
- (display-w-nr (occurs->ms prof-data tchild) 7 port)
- (display-w-mem memuse 10 port)))
- (display-sep-nz-nrs nonreccalls reccalls "+" 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data primary-pi port)
- (newline port)
-
- ;; print children
- (for-each
- (lambda (called-pi)
- (if (not (eq? called-pi primary-pi))
- (let* ((template (profinfo-template called-pi))
- (dfn (profinfo-dfn called-pi))
- (occurs (profinfo-occurs called-pi))
- (calls (number-of-calls primary-pi called-pi))
- (nonreccalls (profinfo-total-nonreccalls called-pi))
- (upcalls (profinfo-upcalls primary-pi called-pi))
- (hist (profinfo-hist called-pi))
- (tchild (profinfo-tchild called-pi))
- (called-cyc (profinfo-cycle called-pi))
- (memuse (profinfo-memoryuse called-pi))
- (share (/ calls upcalls))
- (tself-share (* hist share)) ; TODO: correct when recursive function?
- (tchild-share (* tchild share))
- (memuse-share (* memuse share)))
-
- (display-w "" 3 port)
- (if (has-samples prof-data)
- (begin
- (display-w "" 8 port)
-
- (if (or (not called-cyc)
- (not (eq? called-cyc primary-cyc)))
- (begin
- (display-w-nr (occurs->ms prof-data tself-share) 7 port)
- (display-w-nr (occurs->ms prof-data tchild-share) 7 port)
- (display-w-mem memuse-share 10 port))
- (begin
- (display-w "" 7 port)
- (display-w "" 7 port)
- (display-w "" 10 port)))))
-
- (display-sep-nrs calls nonreccalls "/" 14 port)
-
- (display " " port)
- (display-profinfo-name prof-data called-pi port)
- (newline port))))
- (profinfo-calls prof-data primary-pi))))
- ;; displays functionname and file of a code template
- (define (display-location prof-data template port)
- (let loop ((names (get-template-name-and-modules prof-data template)))
- (if (string? (car names)) (display "\"" port))
- (display (car names) port)
- (if (string? (car names)) (display "\"" port))
- (if (pair? (cdr names))
- (begin (display " in " port)
- (loop (cdr names))))))
- (define (display-profinfo-name prof-data pi port)
- (let* ((template (profinfo-template pi))
- (ton (profinfo-toporder pi))
- (cyc (profinfo-cycle pi)))
-
- (display-location prof-data template port)
- (if cyc
- (begin
- (display " <cycle " port)
- (display (cycleinfo-number cyc))
- (display ">" port)))
-
- (display " [" port)
- (display ton port)
- (display "]" port)))
- ;;; useful stuff
- (define (memq? x l)
- (let loop ((l l))
- (cond ((null? l) #f)
- ((eq? x (car l)) #t)
- (else (loop (cdr l))))))
- (define (remove-duplicates list)
- (do ((list list (cdr list))
- (res '() (if (memq? (car list) res)
- res
- (cons (car list) res))))
- ((null? list)
- res)))
- ;;; DATA CALCULATION
- (define (occurs->ms prof-data occs)
- (if (has-samples prof-data)
- (round (/ (* occs (profile-data-runtime prof-data))
- (profile-data-samples prof-data)))
- 0))
- (define (profile-data-runtime prof-data)
- (let ((st (profile-data-starttime prof-data))
- (et (profile-data-endtime prof-data)))
- (if (or (eq? st (primitives:unspecific))
- (eq? et (primitives:unspecific)))
- (primitives:unspecific)
- (- et st))))
- ;;; cycle stuff
- (define (make-new-cycleinfo prof-data)
- (let ((new (make-cycleinfo (length (profile-data-cycles prof-data)) '())))
- new))
- (define (cycleinfo-add prof-data ci)
- (if (not (memq? ci (profile-data-cycles prof-data)))
- (set-profile-data-cycles! prof-data (cons ci (profile-data-cycles prof-data)))))
- (define (cycleinfo-add-member ci member)
- (let ((members (cycleinfo-members ci)))
- (if (not (memq? member members))
- (cycleinfo-set-members! ci (cons member members)))))
- ;; is profinfo a member of cycle ci?
- (define (cycleinfo-member? ci profinfo)
- (memq? profinfo
- (cycleinfo-members ci)))
- (define (cycleinfo-foreach-member ci f)
- (for-each f (cycleinfo-members ci)))
- ;; number of calls to function called-pi from cycle or from outside of cycle
- (define (calls-int/ext-cycle ci called-pi internal)
- (let ((cnt-calls 0)
- (caller-list (profinfo-callers called-pi)))
- (table-walk (lambda (caller-pi cinfo)
- (if (and (eq? (cycleinfo-member? ci caller-pi)
- internal)
- (not (eq? caller-pi called-pi)))
- (set! cnt-calls (+ cnt-calls (callerinfo-calls cinfo)))))
- caller-list)
- cnt-calls))
- ;; sum up internal calls of the cycle or calls from outside into the cycle
- (define (sumup-calls-int/ext-cycle ci internal)
- (let ((cnt-calls 0))
- (cycleinfo-foreach-member
- ci
- (lambda (member-pi)
- (set! cnt-calls (+ cnt-calls (calls-int/ext-cycle ci member-pi internal)))))
- cnt-calls))
- ;; calls done in the cycle internally
- (define (cycleinfo-internal-calls ci)
- (sumup-calls-int/ext-cycle ci #t))
- ;; calls done from outside into the cycle
- (define (cycleinfo-external-calls ci)
- (sumup-calls-int/ext-cycle ci #f))
- ;; time spent in the functions of the cycle itself
- (define (cycleinfo-hist ci)
- (let ((tt 0))
- (cycleinfo-foreach-member
- ci
- (lambda (pi)
- (set! tt (+ tt (profinfo-hist pi)))))
- tt))
- (define (cycleinfo-memoryuse ci)
- (let ((tt 0))
- (cycleinfo-foreach-member
- ci
- (lambda (pi)
- (set! tt (+ tt (profinfo-memoryuse pi)))))
- tt))
- ;; list of function profinfos the called cycle ci
- (define (cycleinfo-called-from ci)
- (let ((lst '()))
- (cycleinfo-foreach-member
- ci
- (lambda (member-pi)
- (let ((caller-list (profinfo-callers member-pi)))
- ;; add share of every function called from this cycle-function to total
- (table-walk (lambda (caller-pi cinfo)
- (if (and (not (cycleinfo-member? ci caller-pi))
- (not (memq? caller-pi lst)))
- (set! lst (cons caller-pi lst))))
- caller-list))))
- lst))
- ;; list of function profinfos called from cycle ci
- (define (cycleinfo-called-externals prof-data ci)
- (let ((lst '()))
- (cycleinfo-foreach-member
- ci
- (lambda (member-pi)
- (let ((called-list (profinfo-calls prof-data member-pi)))
- ;; add share of every function called from this cycle-function to total
- (for-each (lambda (called-pi)
- (if (and (not (cycleinfo-member? ci called-pi))
- (not (memq? called-pi lst)))
- (set! lst (cons called-pi lst))))
- called-list))))
- lst))
- ;; calls from cycle ci to some other function
- (define (cycleinfo-calls-to ci called-pi)
- (let ((cnt-calls 0))
- (cycleinfo-foreach-member
- ci
- (lambda (member-pi)
- (set! cnt-calls (+ cnt-calls
- (number-of-calls member-pi called-pi)))))
- cnt-calls))
- ;; calls to cycle ci from some other function
- (define (cycleinfo-calls-from ci caller-pi)
- (let ((cnt-calls 0))
- (cycleinfo-foreach-member
- ci
- (lambda (member-pi)
- (set! cnt-calls (+ cnt-calls
- (number-of-calls caller-pi member-pi)))))
- cnt-calls))
- ;; time spent in functions outside the cycle called from member-pi
- (define (cycleinfo-tchild-member prof-data ci member-pi)
- (let ((tt 0)
- (called-list (profinfo-calls prof-data member-pi)))
- ;; add share of every function called from this cycle-function to total
- (for-each (lambda (called-pi)
- (if (and (not (eq? called-pi
- member-pi))
- (not (cycleinfo-member? ci called-pi)))
- (let* ((thiscalls (number-of-calls member-pi called-pi))
- (totalcalls (profinfo-total-nonreccalls called-pi))
- (occs (profinfo-occurs called-pi))
- (share (/ (* occs thiscalls)
- totalcalls)))
- (set! tt (+ tt share)))))
- called-list)
- tt))
- (define (get-callerinfo caller called)
- (let* ((caller-list (profinfo-callers called))
- (cinfo (table-ref caller-list caller)))
- cinfo))
- (define (number-of-calls caller called)
- (let ((cinfo (get-callerinfo caller called)))
- (if cinfo
- (callerinfo-calls cinfo)
- 0)))
- ;; total number of calls from caller to the member or its whole cycle
- ;; (without recursive and cyclic)
- (define (profinfo-upcalls caller-pi called-pi)
- (let* ((cyc-called (profinfo-cycle called-pi))
- (nonrec-calls (profinfo-total-nonreccalls called-pi)))
- (if cyc-called
- (cycleinfo-calls-from cyc-called caller-pi)
- nonrec-calls)))
- ;; total number of calls from caller to the member or its whole cycle
- ;; (without recursive and cyclic)
- (define (profinfo-total-upcalls called-pi)
- (let* ((cyc-called (profinfo-cycle called-pi))
- (nonrec-calls (profinfo-total-nonreccalls called-pi)))
- (if cyc-called
- (sumup-calls-int/ext-cycle cyc-called #f)
- nonrec-calls)))
- ;; number of calls from inside of it's own cycle
- (define (profinfo-total-cycliccalls pi)
- (let ((cyc (profinfo-cycle pi)))
- (if cyc
- (calls-int/ext-cycle cyc pi #t)
- 0)))
- (define (profinfo-timeshare prof-data profinfo)
- (let ((hist (profinfo-hist profinfo)))
- (save/ hist (profile-data-samples prof-data))))
- (define (profinfo-total-ms prof-data profinfo)
- (let ((occurs (profinfo-occurs profinfo)))
- (occurs->ms prof-data occurs)))
- (define (profinfo-self-ms prof-data profinfo)
- (let ((hist (profinfo-hist profinfo)))
- (occurs->ms prof-data hist)))
- ;; returns a list of all profinfos the function calls
- (define (profinfo-calls prof-data caller-pi)
- (let ((lst '()))
- (table-walk (lambda (template called-pi)
- (if (> (number-of-calls caller-pi called-pi) 0)
- (set! lst (cons called-pi lst))))
- (profile-data-templates prof-data))
- (remove-duplicates lst)))
- ;; total non-recursive calls of this function
- (define (profinfo-total-nonreccalls pi)
- (- (profinfo-total-calls pi)
- (profinfo-total-reccalls pi)))
- ;; total recursive calls of this function
- (define (profinfo-total-reccalls pi)
- (let* ((cs (profinfo-callers pi))
- (info (table-ref cs pi)))
- (if info
- (callerinfo-calls info)
- 0)))
- ;; total number of calls (with recursive)
- (define (profinfo-total-calls pi)
- (let ((cs (profinfo-callers pi))
- (total 0))
- (table-walk (lambda (key cinfo)
- (set! total (+ total (callerinfo-calls cinfo))))
- cs)
- total))
- (define (get-sorted-templates prof-data property filter-noncalled?)
- (let ((lst '()))
- (table-walk (lambda (template profinfo)
- (if (or (not filter-noncalled?)
- (> (profinfo-total-calls profinfo) 0))
- (set! lst (cons profinfo lst))))
- (profile-data-templates prof-data))
- (set! lst (sort-list lst
- (lambda (a b)
- (< (property a)
- (property b)))))
- lst))
- (define (propagate-time-from-children prof-data caller-pi)
- (ddisplay "progating time for ")
- (ddisplay (profinfo-template caller-pi))
- (ddisplay " from children...\n")
- (let ((called-list (profinfo-calls prof-data caller-pi)))
- (for-each
- (lambda (called-pi)
- (let* ((cinfo (get-callerinfo caller-pi called-pi))
- (called-cyc (profinfo-cycle called-pi))
- (caller-cyc (profinfo-cycle caller-pi))
- (calls (callerinfo-calls cinfo))
- (share 0)
- (childshare 0))
- (ddisplay (profinfo-template caller-pi))
- (ddisplay " --> ")
- (ddisplay (profinfo-template called-pi))
-
- (if (and (not (eq? caller-pi called-pi))
- (or (not called-cyc) (not (eq? called-cyc caller-cyc))))
- (begin
- (let ((ctself
- (if called-cyc
- (cycleinfo-hist called-cyc)
- (profinfo-hist called-pi)))
- (ctchild
- (if called-cyc
- (cycleinfo-tchild called-cyc)
- (profinfo-tchild called-pi)))
- (nonreccalls
- (if called-cyc
- (cycleinfo-external-calls called-cyc)
- (profinfo-total-nonreccalls called-pi))))
- (ddisplay " ctself: ")
- (ddisplay ctself)
- (ddisplay ", ctchild: ")
- (ddisplay ctchild)
- (ddisplay ", nrc: ")
- (ddisplay nonreccalls)
- (set! share (/ (* ctself calls) nonreccalls))
- (set! childshare (/ (* ctchild calls) nonreccalls))
- )))
- (ddisplay ", calls ")
- (ddisplay (round calls))
- (ddisplay ", share ")
- (ddisplay (round share))
- (ddisplay ", childshare ")
- (ddisplay (round childshare))
- (ddisplay "\n")
- ;; add shares to arc information
- (callerinfo-set-tself! cinfo share)
- (callerinfo-set-tchild! cinfo childshare)
- ;; add everything to child share for parent
- (profinfo-set-tchild! caller-pi
- (+ (profinfo-tchild caller-pi)
- (+ share childshare)))
- (if caller-cyc
- (cycleinfo-set-tchild! caller-cyc
- (+ (cycleinfo-tchild caller-cyc)
- (+ share childshare))))
- ))
- called-list)))
- (define (propagate-times prof-data)
- ;; zero out
- (table-walk (lambda (template profinfo)
- (profinfo-set-tchild! profinfo 0))
- (profile-data-templates prof-data))
- (for-each (lambda (cyc)
- (cycleinfo-set-tchild! cyc 0))
- (profile-data-cycles prof-data))
- (for-each (lambda (template)
- (propagate-time-from-children prof-data template))
- (get-sorted-templates prof-data (lambda (pi) (- (profinfo-dfn pi))) #f)))
- ;;; number function by their depth in the call stack
- (define (profinfo-dfn-set? pi)
- (number? (profinfo-dfn pi)))
- (define (profinfo-dfn-busy? pi)
- (eq? (profinfo-dfn pi) 'busy))
- (define (build-cycle prof-data dfn-stack top-pi)
- ;; is it just a recursive call?
- (if (not (eq? (car dfn-stack) top-pi))
- (begin
- ;; move down the stack till we find ourselves again, adding
- ;; every function to our cycle
- (let ((cyc (make-new-cycleinfo prof-data)))
-
- (let loop ((stack dfn-stack))
- (let* ((pi (car stack))
- (pi-cyc (profinfo-cycle pi)))
-
- (cycleinfo-add-member cyc pi)
-
- ;; if this function is in a cycle already, we all belong to this cycle too
- (if pi-cyc
- (begin
- ;; copy members to this cycle
- (for-each (lambda (memb)
- (cycleinfo-add-member pi-cyc memb))
- (cycleinfo-members cyc))
- (set! cyc pi-cyc)))
-
- (if (and (not (null? (cdr stack)))
- (not (eq? pi top-pi)))
- (loop (cdr stack)))))
-
- ;; add cycle globally
- (cycleinfo-add prof-data cyc)
-
- ;; update cycle information in profinfos
- (for-each (lambda (memb)
- (profinfo-set-cycle! memb cyc))
- (cycleinfo-members cyc))
- ))))
- (define (toporder-numbering prof-data)
- (let ((sorted-templates
- (get-sorted-templates prof-data (lambda (pi) (- (profinfo-occurs pi))) #f))
- (toporder 0))
- (for-each (lambda (profinfo)
- (profinfo-set-toporder! profinfo toporder)
- (set! toporder (+ toporder 1)))
- sorted-templates)))
- (define (remove-uncalled prof-data)
- (let ((tab (profile-data-templates prof-data)))
- (table-walk (lambda (template profinfo)
- (if (and (= (profinfo-total-calls profinfo) 0)
- (not (eq? template (profile-data-root prof-data))))
- (table-set! tab template #f)))
- tab)))
- ;;; numbers all functions by their depth in the call stack
- (define (depth-numbering prof-data)
- (let ((dfn-counter (table-size (profile-data-templates prof-data))))
- (letrec ((depth-number-function
- (lambda (dfn-stack cur-pi)
- ;; already set?
- (if (not (profinfo-dfn-set? cur-pi))
- (begin
- ;; is it busy? must be a cycle
- (if (profinfo-dfn-busy? cur-pi)
- (build-cycle prof-data dfn-stack cur-pi)
- ;; no cycle
- (begin
- ;; pre-visit
- (profinfo-set-dfn! cur-pi 'busy)
-
- ;; process children
- (for-each (lambda (called-pi)
- (depth-number-function (cons cur-pi dfn-stack)
- called-pi))
- (profinfo-calls prof-data cur-pi))
-
- (set! dfn-counter (- dfn-counter 1))
-
- ;; post-visit
- (profinfo-set-dfn! cur-pi dfn-counter)
- )))))))
- ;; zero out
- (table-walk (lambda (template profinfo)
- (profinfo-set-dfn! profinfo 'notset)
- (profinfo-set-cycle! profinfo #f))
- (profile-data-templates prof-data))
- (table-walk (lambda (template profinfo)
- (depth-number-function '() profinfo))
- (profile-data-templates prof-data)))))
- ;; find root and number from there
- ; (if (profile-data-root prof-data)
- ; (let ((root-pi (get-profinfo-from-template prof-data (profile-data-root prof-data))))
- ; (if root-pi
- ; (depth-number-function '() root-pi)))))))
- ;;; RECORDING DATA (while target is running)
- (define *last-stack* #f) ; stack at last interrupt
- (define *cur-stack* #f) ; stack at this interrupt (to be built)
- (define (last-stackentry)
- (if (null? *cur-stack*)
- #f
- (car *cur-stack*)))
- ;; adds one call to the profinfo of CALLED
- (define (profinfo-count-call called caller)
- (if (and called caller)
- (let ((cs (profinfo-callers called)))
- (cond ((table-ref cs caller)
- => (lambda (ci)
- (callerinfo-set-calls! ci (+ 1 (callerinfo-calls ci)))))
- (else
- (table-set! cs caller (make-callerinfo caller 1)))))))
- ;; duplicate from sort/vector-util
- (define (has-element list index)
- (cond
- ((zero? index)
- (if (pair? list)
- (values #t (car list))
- (values #f #f)))
- ((null? list)
- (values #f #f))
- (else
- (has-element (cdr list) (- index 1)))))
- (define (list-ref-or-default list index default)
- (if list
- (call-with-values
- (lambda () (has-element list index))
- (lambda (has? maybe)
- (if has?
- maybe
- default)))
- default))
- (define (set-unseen-all!)
- (and *last-stack*
- (for-each (lambda (se)
- (stackentry-set-seen! se #f))
- *last-stack*)))
- (define (seen? stackentry)
- (and stackentry
- (stackentry-seen stackentry)))
- (define (seen! old-se se)
- (if old-se
- (begin
- (stackentry-set-firstseen! se (stackentry-firstseen old-se))
- (stackentry-set-seen! old-se #t))))
- (define (time-passed se)
- (let* ((firstseen (stackentry-firstseen se))
- (mid (if *profiler-lastrun*
- (- *profiler-thisrun*
- *profiler-lastrun*)
- 0))
- (passed (- *profiler-thisrun*
- firstseen)))
- (- passed (/ mid 2))))
- ;; process the stack entries that have the seen "bit" not set.
- (define (post-process-stack! prof-data call-stack)
- (let ((gone-stackentries '()))
- (if call-stack
- (let loop ((stack call-stack)
- (caller-se #f)
- (seen-templates '()))
- (if (not (null? stack))
- (let* ((called-se (car stack))
- (called-pi (get-profinfo prof-data called-se))
- (template (stackentry-template called-se))
- (reccalls (stackentry-reccalls called-se)))
-
- (if (and (= reccalls 0)
- (not (memq? template seen-templates)))
- (begin
- ;; record occurrence
- (profinfo-set-occurs! called-pi
- (+ (profinfo-occurs called-pi) 1))))
-
- ;; if top element, count as running
- (if (null? (cdr stack))
- (profinfo-set-hist! called-pi
- (+ (profinfo-hist called-pi) 1)))
-
- ;; if gone, record it
- (if (not (stackentry-seen called-se))
- (set! gone-stackentries
- (cons called-se gone-stackentries)))
-
- (loop (cdr stack)
- called-se
- (cons template seen-templates))))))
- gone-stackentries))
- (define (compare-continuation-args c1 c2)
- (let ((ac (continuation-arg-count c1))
- (ac2 (continuation-arg-count c2)))
- (if (= ac ac2)
- (let loop ((i 1))
- (if (< i ac)
- (if (eq? (continuation-arg c1 i)
- (continuation-arg c2 i))
- (loop (+ i 1))
- #f)
- #t))
- #f)))
- (define (process-stack-traces! prof-data)
- (let ((stat-new-funcs '())
- (stat-gone-funcs '())
- (stat-new-caller #f)
- (stat-top #f))
-
- ;; go from bottom to top and count calls
- (let loop ((pos 0)
- (stack *cur-stack*)
- (caller-se #f)
- (diff-found #f))
- (if (not (null? stack))
- (let ((new-se (car stack)))
- ;; compare with last stack
- (let ((old-se (list-ref-or-default *last-stack* pos #f))
- (rcdcall #f)
- (old-diff-found diff-found))
- (if (or (not old-se) ; not on old stack
- diff-found)
- (begin
- (set! rcdcall #t)
- (set! diff-found #t))
- (if (not (eq? (stackentry-template old-se) ; other template => other func
- (stackentry-template new-se)))
- (begin
- (set! rcdcall #t)
- (set! diff-found #t))
- ;; same template...
- (let ((old-cont (stackentry-cont old-se))
- (new-cont (stackentry-cont new-se)))
- (if (not (eq? old-cont new-cont)) ; other continuation, something changed
- (begin
- (set! diff-found #t) ; remember change upwards...
- (if (and (eq? (continuation-pc old-cont) ; same pc and arg-count, else
- (continuation-pc new-cont)) ; may be just other place in func
- (eq? (continuation-code old-cont)
- (continuation-code new-cont))
- (compare-continuation-args old-cont new-cont)) ; detects most tailcalls
- (set! rcdcall #t)))))))
- (if (and caller-se
- (not (eq? diff-found
- old-diff-found)))
- (set! stat-new-caller caller-se))
-
- (if rcdcall
- (begin ; new call to fun
- (set! stat-new-funcs (cons new-se stat-new-funcs))
- (if (and caller-se
- *measure-noninstr?*)
- (record-call! prof-data
- (stackentry-template caller-se) 0
- (stackentry-template new-se) 0
- #f))
- )
- (seen! old-se new-se))
-
- (loop (+ pos 1)
- (cdr stack)
- new-se
- diff-found)))
- (set! stat-top caller-se)))
- (set! stat-gone-funcs
- (post-process-stack! prof-data *last-stack*))
- (analyze-memory-usage prof-data stat-top stat-new-funcs stat-new-caller stat-gone-funcs)
-
- ))
- (define (record-template! cont template)
- (if template
- (if (eq? (closure-template profile-count)
- template)
- (begin
- ; (display "hitting profile-count, throwing stack away\n")
- (set! *cur-stack* '()))
- (begin
- (let ((lse (last-stackentry))
- (nse (make-stackentry cont template)))
-
- (if (and lse
- (eq? (stackentry-template lse)
- template))
- (stackentry-set-reccalls! lse
- (+ 1 (stackentry-reccalls lse))))
-
- ;; consider recursion (disabled)
- (set! *cur-stack*
- (cons nse *cur-stack*)))))))
- ;; main record function (called from interrupt handler)
- (define (record-continuation! prof-data cont)
-
- ;; init
- (set! *cur-stack* '())
- (set! *profiler-lastrun* *profiler-thisrun*)
- (set! *profiler-thisrun* (run-time)) ; we cap this here, profiler could run some time
- (set! *cur-avail-memory* (available-memory))
- (set! *cur-gc-count* (get-current-gc-count))
- (set-profile-data-samples! prof-data
- (+ 1 (profile-data-samples prof-data)))
-
- ;; record the current template
- (record-template! cont (find-template cont))
- ;; decent until we reach our own continuation
- (let loop ((cont (continuation-cont cont)))
- (if (and cont
- (not (profiler-continuation? cont)))
- (let ((parent (continuation-cont cont)))
- (record-template! cont (continuation-template cont))
- (loop parent))))
- ;; record our root template
- (record-template! #f (profile-data-root prof-data))
-
- ;; process the stack built above
- (if (not (null? *cur-stack*))
- (begin
- (process-stack-traces! prof-data)
-
- ;; save old stack
- (set! *last-stack* *cur-stack*)
- (set-unseen-all!)))
- ;; save memory status
- (set! *last-avail-memory* (available-memory))
- (set! *last-gc-count* (get-current-gc-count)))
- ;; searchs the (moving?) template in the continuation
- (define (find-template cont)
- (let ((len (primitives:continuation-length cont)))
- (let loop ((i 0))
- (and (< i len)
- (let ((elt (primitives:continuation-ref cont i)))
- (if (template? elt)
- elt
- (loop (+ i 1))))))))
- ;;;;;; HEAP PROFILER
- ;; see commit messages and documentation
- (define (available-memory)
- (primitives:memory-status (enum memory-status-option available) #f))
- (define (get-current-gc-count)
- (primitives:memory-status (enum memory-status-option gc-count) #f))
- (define (gc-running-meanwhile?)
- (> *cur-gc-count* *last-gc-count*))
- (define (analyze-memory-usage prof-data top new caller gone)
- (if (gc-running-meanwhile?)
- (begin
- ;; we need to know the free memory after GC to fix this
- #f)
- (begin
- (let* ((usage (- *last-avail-memory*
- *cur-avail-memory*))
- (cntnew (length new))
- (cntgone (length gone))
- (dotop (and top
- (= cntnew 0)
- (= cntgone 0)))
- (totcnt (+ (if caller 1 0)
- cntnew
- cntgone))
- (avgusage (if (= totcnt 0) 0 (/ usage totcnt)))
- (addmem (lambda (se amount)
- (let ((pi (get-profinfo prof-data se)))
- (profinfo-set-memoryuse!
- pi
- (+ (profinfo-memoryuse pi)
- amount))))))
- (if (> usage 0)
- (begin
- (set-profile-data-memoryuse!
- prof-data
- (+ (profile-data-memoryuse prof-data) usage))
- ;; if the template at the top still the same, add all memory to it
- (if dotop
- (addmem top usage)
- ;; else distribute memory usage to all relevant templates
- (begin
- (if caller (addmem caller avgusage))
- (for-each (lambda (se) (addmem se avgusage)) new)
- (for-each (lambda (se) (addmem se avgusage)) gone)))))))))
- ; (warning
- ; 'profile-analyse-memory-usage
- ; (string-append "usage < 0, somehow memory got free with no GC run: "
- ; (number->string *last-avail-memory*)
- ; " -> "
- ; (number->string *cur-avail-memory*)))
- (define (record-call! prof-data caller-template caller-pc called-template called-pc instrumented?)
- (let* ((caller-profinfo (get-profinfo-from-template
- prof-data
- (if *first-call?*
- (begin
- (set! *first-call?* #f)
- (profile-data-root prof-data))
- caller-template)))
- (called-profinfo (get-profinfo-from-template prof-data called-template))
- (min-pc (profinfo-min-pc called-profinfo))
- (only-instrumented? (profinfo-instrumented? called-profinfo)))
- ;; only count this call, if counted by profile-count or
- ;; by the sampling interrupt if it was not counted by profile-count yet
- (if (or instrumented?
- (not only-instrumented?))
- (begin
- ;; store the program counter of the first call to the function
- (if (not min-pc)
- (begin
- (set! min-pc called-pc)
- (profinfo-set-min-pc! called-profinfo min-pc)
- (if instrumented?
- (profinfo-set-instrumented?! called-profinfo #t))))
-
- ;; we need to check the program counter, otherwise let-s would be counted
- ;; as a call
- (if (<= called-pc min-pc)
- (profinfo-count-call called-profinfo caller-profinfo))))))
- ;;; called from every profiled function (mcount in gprof),
- ;;; if profiler-instrumentation optimizer enabled for this package
- (define (profile-count)
- (if *active-profile-data*
- (let ((x (primitive-cwcc profile-count-cont)))
- x)))
- (define (profile-count-cont cont)
- (let* ((cont-called (continuation-cont cont))
- (cont-caller (continuation-cont cont-called))
- (template-called (continuation-template cont-called))
- (template-caller (continuation-template cont-caller))
- (pc-called (continuation-pc cont-called))
- (pc-caller (continuation-pc cont-caller)))
-
- ; (display template-caller)
- ; (display " (")
- ; (display pc-caller)
- ; (display ") calls ")
- ; (display template-called)
- ; (display " (")
- ; (display pc-called)
- ; (display ")\n")
- (record-call! *active-profile-data* template-caller pc-caller template-called pc-called #t)))
- (define (get-profinfo-from-template prof-data template)
- (or (table-ref (profile-data-templates prof-data) template)
- (make-profinfo prof-data template)))
- ;; adds one call to the profinfo of CALLED
- (define (profinfo-count-call called caller)
- (if (and called caller)
- (let ((cs (profinfo-callers called)))
- (cond ((table-ref cs caller)
- => (lambda (ci)
- (callerinfo-set-calls! ci (+ 1 (callerinfo-calls ci)))))
- (else
- (table-set! cs caller (make-callerinfo caller 1)))))))
|