Skip to content

(v0.x) Basic Usage

Jump to bottom
Ben Davies edited this page Feb 11, 2021 · 1 revision

Anatomy of a trace

In the documentation on traced routine calls below, this is the output produced:

1 ROUTINE CALL [1 @ 1580368875.642086]
<== sub times-two (GLOBAL)
    $x: 2
==> 4

This is formatted in such a way as to be both human-readable and possible to parse with a grammar. Let's take a look at what each individual part of this indicates:

1 ROUTINE CALL [1 @ 1580368875.642086]

This is the title of the trace, which contains metadata about the event traced. The 1 at its start is the trace's ID, the ROUTINE to its right is the trace's category, and the CALL to the right of that is the trace type. Within the brackets at the end, 1 is the ID of the thread from which the trace was taken, and 1580368875.642086 is the trace's timestamp.

<== sub times-two (GLOBAL)

This is the header of the trace, which contains the object being traced. This will always be prefixed with <==.

    $x: 2

This is one of the entries of the trace. These will always be indented with 4 more spaces than the rest of the trace. These will always be pairs of some sort, but what information they contain varies from type to type of trace.

==> 4

This is the footer of the trace. This will either be prefixed with ==> if the event traced succeeded, or !!! if it threw an exception. To the right of that is the result of the event traced.

Tracers

Tracing is handled by the $*TRACER superglobal. This is set to Tracer::Default[$*OUT] by default, but may be any Tracer object. Tracer::Default is a parametric type accepting any IO::Handle instance that outputs traces to the handle it was parameterized with in a way that's both human-readable and possible to parse with a grammar.

$*TRACER can be overridden by declaring a global of the same name. For example, outputting traces to a .trace file instead of $*OUT can be done by writing this before any traces get made:

use Tracer::Default;
$GLOBAL::TRACER = Tracer::Default['.trace'.IO.open: :w];
LEAVE $*TRACER.handle.close;

For information on how to write your own Tracers, refer to the Custom Tracing page.

Tracing

Routines

Any Raku routine (subroutine, method, submethod, regex, etc.) can be traced by applying the is traced trait to them. For example, a &times-two routine can be traced like so:

sub times-two(Numeric:D $x --> Numeric:D) is traced { $x * 2 }

When invoked with 2, this will produce a trace that looks something like this:

1 ROUTINE CALL [1 @ 1580368875.642086]
<== sub times-two (GLOBAL)
    $x: 2
==> 4

In the trace's header, GLOBAL is the package to which the routine belongs to, and sub times-two is the declaration the routine was likely to be created with (this is not guaranteed to be 100% accurate, but should be accurate in most cases). The trace's entries are pairs of the routine's parameters mapped to the arguments given. The trace's footer is the return value of the trace or the type of exception thrown when one is thrown during the call.

Variables and Attributes

Assignments to variables can be traced:

my $foo is traced = 1;
my @bar is traced = 1, 2, 3;

This produces output similar to this:

1 VARIABLE ASSIGN [1 @ 1588297125.015085]
<== my $foo
==> 1
2 VARIABLE STORE [1 @ 1588297125.025227]
<== my @bar
==> [1 2 3]

A distinction is made between scalar assignments and positional/associative assignments, as the latter is actually a STORE method call, thus the differing ASSIGN and STORE trace types.

Attributes may also be traced in a similar manner:

class Foo {
    has $!foo is traced = 1;
    has @!bar is traced = 1, 2, 3;
}
Foo.new;

This has similar output to variable assignments:

1 ATTRIBUTE ASSIGN [1 @ 1588297287.253161]
<== $!foo (Foo)
==> 1
2 ATTRIBUTE STORE [1 @ 1588297287.263557]
<== @!bar (Foo)
==> [1 2 3]

Types

class :: is traced { ... }

What tracing a type will actually do depends heavily on the type's HOW. The rest of this section will cover the various features of types that can be traced.

Metamodel::MethodContainer

Any type supporting method storage (which includes methods, submethods, and regexes) can have calls to the methods they declare get traced using the same tracing support that routines use. For example, applying is traced to Foo here will make calls to its foo method get traced:

class Foo is traced {
    method foo(--> 1) { }
}

If it's undesirable for a method to be traceable, the is-hidden-from-backtrace trait can be applied to exclude it from trace output.

Note: this only traces regular and proto methods! Private methods, metamethods, and multi methods will not get traced by this.

Metamodel::MultiMethodContainer

Any type supporting multi method storage can have calls to the multi methods they declare get traced. The is hidden-from-backtrace trait can be used to exclude these from trace output if this is undesirable.

Metamodel::PrivateMethodContainer

Any type supporting private method storage can have calls to the private methods they declare get traced. The is hidden-from-backtrace trait can be used to exclude these from trace output if this is undesirable.

Metamodel::MetaMethodContainer

Any type supporting metamethod storage can have calls to the metamethods they declare get traced. The is hidden-from-backtrace trait can be used to exclude these from trace output if this is undesirable.

Metamodel::Stashing

Any type supporting stashes (WHO/::) can have symbol lookups, binds, and assignments get traced. For example, the following code:

my module Foo is traced {
    constant Bar = 0;
}

my Int:D $value = Foo::Bar;
Foo::<Bar>;
Foo::<Bar> := Proxy.new:
    FETCH => sub FETCH(\) { $value },
    STORE => sub STORE(\, Int:D $new-value) { $value = $new-value };
Foo::<Bar> = 1;

Will produce output like this:

1 STASH LOOKUP [1 @ 1580368290.036877]
<== Foo::Bar
==> 0
2 STASH BIND [1 @ 1580368290.048831]
<== Foo::Bar
    old: 0
    new: 0
==> 0
3 STASH ASSIGN [1 @ 1580368290.067287]
<== Foo::Bar
    old: 0
    new: 1
==> 1

Note that while Foo::Bar is looked up twice, it only gets traced once; in cases where the compiler knows the value of a direct symbol lookup (which is the case with constants), it will not get traced.

In stash traces, the header will include the symbol being looked up, and the footer will include the resulting value for that symbol. For symbol lookups, there will be no entries, but for binds and assignments, there will be an old entry for the original value for this symbol and a new entry for the value being bound or assigned to it.

Metamodel::AttributeContainer

Any type supporting attributes can have assignments to any of its instances' attributes get traced.

Clone this wiki locally