Selkie.git | t/ | 81-trace.rakutest

---

use Test;
use lib 'lib';

use Selkie::Trace;

plan 4;

sub tmp-path(Str:D $suffix --> Str) {
    $*TMPDIR.add("selkie-trace-{$*PID}-{now.Int}-$suffix").Str;
}

subtest "off mode records nothing" => {
    plan 2;
    Selkie::Trace.init(mode => 'off');
    nok Selkie::Trace.enabled, "trace disabled";
    is Selkie::Trace.mode, 'off', "mode reports off";
    Selkie::Trace.shutdown;
};

subtest "trace mode writes Chrome Trace JSON" => {
    plan 7;
    my $path = tmp-path('trace.json');
    Selkie::Trace.init(mode => 'trace', trace-path => $path);
    ok Selkie::Trace.trace-enabled, "trace mode enabled";
    ok $path.IO.e, "trace file is created at init";
    my $span = Selkie::Trace.start('test.span', cat => 'test', args => %(thing => 'value'));
    sleep 0.01;
    $span.finish(ok => True);
    Selkie::Trace.instant('test.instant', cat => 'test', args => %(n => 1));
    Selkie::Trace.shutdown;

    ok $path.IO.e, "trace file written";
    my $json = $path.IO.slurp;
    like $json, /'"traceEvents"'/, "trace file has traceEvents";
    like $json, /'test.span'/, "trace file has span event";
    unlike $json, /'"ts":null'/, "trace timestamps are numeric";
    unlike $json, /'"dur":null'/, "trace durations are numeric";
    $path.IO.unlink if $path.IO.e;
};

subtest "slow mode writes thresholded JSONL spans" => {
    plan 4;
    my $path = tmp-path('slow.jsonl');
    Selkie::Trace.init(
        mode      => 'slow',
        slow-path => $path,
        slow-ms   => 0e0,
    );
    ok Selkie::Trace.slow-enabled, "slow mode enabled";
    my $span = Selkie::Trace.start('slow.span', cat => 'test');
    sleep 0.01;
    $span.finish(answer => 42);
    Selkie::Trace.shutdown;

    ok $path.IO.e, "slow file written";
    my $jsonl = $path.IO.slurp;
    like $jsonl, /'slow.span'/, "slow file has span";
    like $jsonl, /'"dur_ms"'/, "slow file has duration";
    $path.IO.unlink if $path.IO.e;
};

subtest "writer thread: multi-thread producers all land, shutdown drains" => {
    plan 4;
    # Trace-mode events are enqueued lock-free and written by one
    # dedicated writer thread; shutdown must close the channel, JOIN
    # the writer, and only then write the JSON tail — so a file read
    # after shutdown contains every event produced from any thread,
    # and stays structurally valid JSON.
    my $path = tmp-path('writer.json');
    Selkie::Trace.init(mode => 'trace', trace-path => $path);
    my @workers = (^4).map: -> $w {
        start {
            for ^25 -> $i {
                my $span = Selkie::Trace.start("worker.span",
                    cat => 'test', args => %(worker => $w, i => $i));
                $span.finish(ok => True);
            }
        }
    };
    await @workers;
    Selkie::Trace.shutdown;

    my $json = $path.IO.slurp;
    my $count = +$json.comb('"worker.span"');
    is $count, 100, 'all 100 events from 4 threads landed';
    like $json, /'trace/shutdown'/, 'shutdown marker is present';
    like $json, /'"displayTimeUnit"' \s* ':' \s* '"ms"' '}' $/,
        'JSON tail written after the drain';
    lives-ok {
        my $span = Selkie::Trace.start('late.span', cat => 'test');
        $span.finish(ok => True) with $span;
        Selkie::Trace.instant('late.instant', cat => 'test');
    }, 'producers racing past shutdown are safely dropped';
    $path.IO.unlink if $path.IO.e;
};