[racket] Profiling mostly macro-generated definitions?

From: J. Ian Johnson (ianj at ccs.neu.edu)
Date: Tue Aug 28 14:06:10 EDT 2012

My functions surely have names. I would have at least thought that hash-set and hash-ref would be listed as taking a considerable amount of time, since that's my main data structure.

I just get the following after a 6 minute run.

Profiling results
  Total cpu time observed: 0ms (out of 299999ms)
  Number of samples taken: 5496 (once every 0ms)
  (Hiding functions with self<1.0% and local<2.0%: 30 of 30 hidden)

Idx  Total    Self    Name+srcLocal%
     ms(pct)  ms(pct)   Callee

I changed the renderer to not hide anything, and the output did not include hash-set, hash-ref, or (more surprisingly) my fixpoint function that does all the work. It is a defined, named function.
All the functions it rendered contributed 0% to the running time.


----- Original Message -----
From: "Robby Findler" <robby at eecs.northwestern.edu>
To: "J. Ian Johnson" <ianj at ccs.neu.edu>
Cc: "users" <users at racket-lang.org>
Sent: Tuesday, August 28, 2012 1:23:35 PM GMT -05:00 US/Canada Eastern
Subject: Re: [racket] Profiling mostly macro-generated definitions?

Whether the functions were created by macro expansion or not won't
matter to the profiler. Maybe these functions are just not showing up
in the profile because they don't get called a lot?

But if you want to be extra sure, it is possible that if the functions
don't have a name (you can check this by using object-name on the
functions at runtime) they might get dropped from the profile. Most
functions will have a name, either because they are in a let or a
define or because the name is derived from the source location
information, but it is possible that a function might have neither of
these. You can usually fix this by introducing a let.


On Tue, Aug 28, 2012 at 9:47 AM, J. Ian Johnson <ianj at ccs.neu.edu> wrote:
> What is the proper way to get the statistical profiler to be aware of function definitions that are created by macro expansion (in different splicing-syntax-parameterize'd blocks, if that matters)?
> I have a data flow analysis framework that is parameterized by the Might/Van Horn metafunctions from Abstracting Abstract Machines, and some others that are necessary for a real-world analysis (delta axiom approximations, pretty printers, etc). This parameterization is at compile-time, which generates several definitions local to different syntax-parameterizations. At the top level, I have my test suite that I want to now profile, since I'm hitting some performance issues. The profiler finds a few functions that it hides since they don't contribute to much of the running time. Everything else is not profiled, it seems.
> Example generator:
> (define-syntax (with-basic-k-trunc-analysis stx)
>   (syntax-case stx ()
>     [(_ (k trunc?) body1 body ...)
>      (syntax/loc stx
>        (syntax-parameterize
>            ([contour-length (λ (stx) #'k)] ; should be constant
>             [truncate-rt? (λ (stx) #'trunc?)] ; should be constant
>             [alloc (make-rename-transformer #'base-alloc)]
>             [addr-lookup (make-rename-transformer #'base-addr-lookup)]
>             [join-stores (make-rename-transformer #'base-join-stores)]
>             [compare-σ (make-rename-transformer #'base-compare-σ)]
>             [compare-w (make-rename-transformer #'base-compare-w)]
>             [step-parameters (make-rename-transformer #'base-step-parameters)]
>             [initial-parameters (make-rename-transformer #'base-initial-parameters)]
>             [combine-parameters/exit (make-rename-transformer #'base-combine-parameters/exit)]
>             [pretty-local (make-rename-transformer #'base-pretty-local)]
>             [pretty-wide (make-rename-transformer #'base-pretty-wide)])
>          (begin
>            (define (k-contour-add t label) <blah>)
>            (define (base-tick s) <blah>)
>            (syntax-parameterize ([tick (make-rename-transformer #'base-tick)])
>               body1 body ...))))]))
> There are several macros like this, all used in the same module as the invocation of the profiler. The top level wrapper is the splicing parameterization:
> (define-syntax-rule (with-all-widening body1 body ...)
>   (splicing-syntax-parameterize
>    ([widening 'all]
>     [add-context (make-rename-transformer #'values)]
>     [combine-context (make-rename-transformer #'combine-all)]
>     [no-state (make-rename-transformer #'no-state-all-widen)])
>    body1 body ...))
> Thanks,
> -Ian
> ____________________
>   Racket Users list:
>   http://lists.racket-lang.org/users

Posted on the users mailing list.