From 9f5169175bd4346d707207d0246b415b4d8eb43a Mon Sep 17 00:00:00 2001 From: Sam Tobin-Hochstadt Date: Sat, 26 Oct 2013 11:05:45 -0400 Subject: [PATCH] Implement statistical errortrace-based profiling. Add a mode to the profiler to use continuation marks inserted by the errortrace annotator instead of the runtime. Split `syntax/source-syntax` out from Typed Racket as a separate package, and use it to give better names for errortrace stack frames. Use caching to speed it up substantially when called repeatedly (as errortrace does). Also, document (internally) the format used by errortrace marks. original commit: 1e7eb34ba170b6aad77ee67c0f4b802950ff1a4b --- pkgs/profile-pkgs/profile-doc/info.rkt | 2 ++ .../profile/scribblings/sampler.scrbl | 10 ++++-- .../profile/scribblings/toplevel.scrbl | 12 ++++++- pkgs/profile-pkgs/profile-lib/info.rkt | 2 +- pkgs/profile-pkgs/profile-lib/main.rkt | 6 ++-- pkgs/profile-pkgs/profile-lib/sampler.rkt | 31 ++++++++++++++++--- 6 files changed, 53 insertions(+), 10 deletions(-) diff --git a/pkgs/profile-pkgs/profile-doc/info.rkt b/pkgs/profile-pkgs/profile-doc/info.rkt index 0e2c38b..0ecfc38 100644 --- a/pkgs/profile-pkgs/profile-doc/info.rkt +++ b/pkgs/profile-pkgs/profile-doc/info.rkt @@ -5,6 +5,8 @@ (define build-deps '("base" "scribble-lib" "profile-lib" + "errortrace-doc" + "errortrace-lib" "racket-doc")) (define pkg-desc "documentation part of \"profile\"") diff --git a/pkgs/profile-pkgs/profile-doc/profile/scribblings/sampler.scrbl b/pkgs/profile-pkgs/profile-doc/profile/scribblings/sampler.scrbl index f50f95d..b39950c 100644 --- a/pkgs/profile-pkgs/profile-doc/profile/scribblings/sampler.scrbl +++ b/pkgs/profile-pkgs/profile-doc/profile/scribblings/sampler.scrbl @@ -1,7 +1,8 @@ #lang scribble/doc @(require scribble/manual - (for-label racket/base racket/contract profile/sampler profile/analyzer)) + (for-label racket/base racket/contract profile/sampler profile/analyzer + errortrace/errortrace-key)) @title[#:tag "sampler"]{Collecting Profile Information} @@ -11,7 +12,8 @@ (listof (or/c thread? custodian?)))] [delay (>=/c 0.0)] [super-cust custodian? (current-custodian)] - [custom-keys (listof any/c) '()]) + [custom-keys (listof any/c) '()] + [#:use-errortrace? use-errortrace? any/c #f]) ((symbol?) (any/c) . ->* . any/c)]{ Creates a stack-snapshot collector thread, which tracks the given @@ -26,6 +28,10 @@ When @racket[custom-keys] are provided, the sampler takes snapshots of the continuation marks corresponding to the given keys, in addition to taking snapshots of the stack. +When @racket[use-errortrace?] is not @racket[#f], the @racket[errortrace-key] is +used to sample snapshots instead of the implicit key used by +@racket[continuation-mark-set->context]. + The resulting value is a controller function, which consumes a message consisting of a symbol and an optional argument, and can affect the sampler. The following messages are currently supported: diff --git a/pkgs/profile-pkgs/profile-doc/profile/scribblings/toplevel.scrbl b/pkgs/profile-pkgs/profile-doc/profile/scribblings/toplevel.scrbl index d4dcc3d..3f204f0 100644 --- a/pkgs/profile-pkgs/profile-doc/profile/scribblings/toplevel.scrbl +++ b/pkgs/profile-pkgs/profile-doc/profile/scribblings/toplevel.scrbl @@ -2,6 +2,7 @@ @(require scribble/manual (for-label racket/base racket/contract profile profile/sampler + errortrace/errortrace-lib (only-in profile/analyzer analyze-samples profile?) (prefix-in text: profile/render-text))) @@ -23,7 +24,8 @@ intended as a convenient tool for profiling code. [#:periodic-renderer periodic-renderer (or/c #f (list/c (>=/c 0.0) (profile? . -> . any/c))) - #f]) + #f] + [#:use-errortrace? use-errortrace? any/c #f]) void?]{ Executes the given @racket[thunk] and collect profiling data during @@ -39,6 +41,14 @@ can customize the profiling: be close, but not identical to, the frequency in which data is actually sampled. (The @racket[delay] value is passed on to @racket[create-sampler], which creates the sampler thread.)} + +@item{When @racket[use-errortrace?] is not @racket[#f], more accurate + stack snapshots are captured using + @other-doc['(lib "errortrace/scribblings/errortrace.scrbl")]. Note that + when this is provided, it will only profile uncompiled files and files + compiled while using @racket[errortrace-compile-handler], and the profiled program + must be run using @commandline{racket -l errortrace -t program.rkt} + Removing compiled files (with extension @tt{.zo}) is sufficient to enable this.} @item{Due to the statistical nature of the profiler, longer executions result in more accurate analysis. You can specify a number of diff --git a/pkgs/profile-pkgs/profile-lib/info.rkt b/pkgs/profile-pkgs/profile-lib/info.rkt index 7b91a59..9cb70b8 100644 --- a/pkgs/profile-pkgs/profile-lib/info.rkt +++ b/pkgs/profile-pkgs/profile-lib/info.rkt @@ -1,7 +1,7 @@ #lang info (define collection "profile") -(define deps '("base")) +(define deps '("base" "errortrace-lib")) (define build-deps '("at-exp-lib" "rackunit-lib")) diff --git a/pkgs/profile-pkgs/profile-lib/main.rkt b/pkgs/profile-pkgs/profile-lib/main.rkt index 3a14dbe..a6bb5f9 100644 --- a/pkgs/profile-pkgs/profile-lib/main.rkt +++ b/pkgs/profile-pkgs/profile-lib/main.rkt @@ -11,12 +11,14 @@ #:repeat [rpt 1] #:threads [threads? #f] #:render [renderer text:render] - #:periodic-renderer [periodic-renderer #f]) + #:periodic-renderer [periodic-renderer #f] + #:use-errortrace? [et? #f]) (define cust (and threads? (make-custodian (current-custodian)))) (define sampler (create-sampler (if threads? (list cust (current-thread)) (current-thread)) - delay)) + delay + #:use-errortrace? et?)) (define periodic-thread (and periodic-renderer (let ([delay (car periodic-renderer)] diff --git a/pkgs/profile-pkgs/profile-lib/sampler.rkt b/pkgs/profile-pkgs/profile-lib/sampler.rkt index f29b0e9..ddd44b0 100644 --- a/pkgs/profile-pkgs/profile-lib/sampler.rkt +++ b/pkgs/profile-pkgs/profile-lib/sampler.rkt @@ -6,8 +6,24 @@ (provide create-sampler) +(require errortrace/errortrace-key) + +;; (cons sexp srcloc) -> (cons symbol srcloc) +;; just take the first symbol we find +(define (errortrace-preprocess frame) + (cons (and (car frame) + (let loop ([e (car frame)]) + (cond [(symbol? e) e] + [(pair? e) (loop (car e))] + [else (error 'errortrace-preprocess + "unexpected frame: ~a" frame)]))) + (and (cdr frame) + (apply srcloc (cdr frame))))) + ;; create-sampler : creates a sample collector thread, which tracks the given ;; `to-track' value every `delay' seconds. +;; Uses errortrace annotations when #:use-errortrace? is specified, otherwise +;; uses the native stack traces provided by `cms->context`. ;; * The input value can be either a thread (track just that thread), a ;; custodian (track all threads managed by the custodian), or a list of ;; threads and/or custodians. If a custodian is given, it must be @@ -57,7 +73,8 @@ ;; same format as the output of continuation-mark-set->list*. (define (create-sampler to-track delay [super-cust (current-custodian)] - [custom-keys #f]) + [custom-keys #f] + #:use-errortrace? [do-errortrace #f]) ;; the collected data (define snapshots '()) ;; listof (cons continuation-mark-key value/#f) @@ -116,9 +133,15 @@ (set! snapshots (cons (list* (thread-id t) (current-process-milliseconds t) - (map intern-entry - (continuation-mark-set->context - (continuation-marks t)))) + (if do-errortrace + (for/list ([frame (in-list + (continuation-mark-set->list + (continuation-marks t) + errortrace-key))]) + (intern-entry (errortrace-preprocess frame))) + (map intern-entry + (continuation-mark-set->context + (continuation-marks t))))) snapshots)))] [(custodian? t) (for-each loop (custodian-managed-list t super-cust))]