Andy Wingo <wi...@pobox.com> writes:
> Hi Neil,
>
> I really must be miscommunicating here :)
I think you just left out a couple of details. Plus I think you're
assuming that there is no requirement (or usefulness) for tracing or
profiling below the program level - i.e. within a sequence of VM
operations.
Is that assumption correct? Doesn't it mean that we can profile/trace
less as the compiler becomes cleverer?
> Let's see if I can do a better job.
Thank you! :-)
> ,tr (short for ,trace) traces *all* function applications that happen
> when executing a form.
OK.
>> - What if the function that you want to trace is not the one that you
>> want to invoke at top level?
>>
>> - What if you want to trace several functions within a given
>> computation?
>
> This works. You get a lot of output, as things are currently; but we can
> restrict tracing to work only on certain procedures, etc.
That sounds good. I would suggest that we allow for any combination of
- some procedures for which only call+args and return value are
traced
- some procedures for which all applications within the dynamic context
of those procedures are traced
- some top-level computation (presumably including some of the previous
procedures), for which the tracing function is enabled.
>> - Alternatively, if ,tr is supposed to mean "trace everything within
>> this computation", why aren't there trace lines for the applications
>> of `or', `=' and so on?
>
> Perhaps it would help to disassemble fibo itself:
[...]
> The VM can fire hooks at function application, leaving a function,
> entering a new frame, leaving a frame, on "next instruction", and a
> couple other places. The tracer hooks into the first four. As you can
> see from the disassembly, there is no "or" -- it gets expanded away by
> psyntax anyway. = is on lines 9 and 28, inlined into the body. So you
> see that the only function that is called is... fibo itself. That's why
> it's the only one in the trace.
Thanks for the detailed explanation. I understand, but I wonder (as
also above) if this will be useful enough in practice.
> You can't get any more information on the function call level in this
> example, because it's not complicated enough. But try it on anything
> else -- (resolve-module '(gnome gtk)) for example:
>
> % cumulative self
> time seconds seconds name
> 14.18 0.51 0.26 write-bytecode
> 9.22 0.17 0.17 #<program 9f1c1e0 at
> language/scheme/spec.scm:40:16 (port env)>
> 7.09 0.13 0.13 byte-length
> 4.26 0.31 0.08 glil->assembly
> 2.13 0.17 0.04 dump-object
> 2.13 0.15 0.04 #{\get-global-definition-hook\\\ 90}#
> 2.13 0.04 0.04 write-byte
> 2.13 0.04 0.04 module-ref
> 1.42 1.80 0.03 #<program 9e4ed20 at ice-9/boot-9.scm:2039:4
> (name . args)>
> 1.42 0.31 0.03 #{\syntax-type\\\ 162}#
> 1.42 0.15 0.03 #<program a10ef50 at language/assembly.scm:63:8
> (x len)>
> 1.42 0.06 0.03 #{\id-var-name\\\ 150}#
> 1.42 0.03 0.03 #<program a00a870 at
> language/tree-il/fix-letrec.scm:57:18 (x unref ref set simple lambda*
> complex)>
> 1.42 0.03 0.03 object->assembly
> 0.71 1.33 0.01 eval
>
> This is when it had to compile a bunch of things, so really it's a test
> of the compiler. Totally useful information though -- we really need to
> speed up the bytecode writer!
Yes, that's pretty nice.
I'm just not sure how things work as the generated code becomes more
optimised. For example, when a `map' procedure is inlined. But maybe
that's a fundamental problem, and it's well known (except to me!) that
you can't unambiguously trace or profile optimised code.
> Regards,
>
> Andy
Regards,
Neil
