[racket] Profiling mostly macro-generated definitions?

Not unless that's default behavior.
-Ian
----- 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 2:08:15 PM GMT -05:00 US/Canada Eastern
Subject: Re: [racket] Profiling mostly macro-generated definitions?

The profiler doesn't include primitive functions like hash-set and
hash-ref (and anyways you might see many calls to them, but you won't
see them taking a lot of time, since they are pretty fast on a
per-call basis).

But yes, something seems wrong with that profile. Does your program
use multiple (racket) threads?

Robby

On Tue, Aug 28, 2012 at 1:06 PM, J. Ian Johnson <ianj at ccs.neu.edu> wrote:
> 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)
>
> ====================================
>                         Caller
> 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.
>
> -Ian
>
> ----- 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.
>
> Robby
>
> 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