Module: nupp.profile

Profiling, in two channels.

  • profile.sample is the statistical sampler. A timer interrupts the program and writes down where it was; what comes back is collapsed-stack text, the format speedscope.app, FlameGraph.pl and inferno all read. It answers where the time went.
  • profile.trace watches the JIT give up. It aggregates trace aborts, so blacklisted hot code, a bytecode the compiler will not record, and traces that grew past a limit all become rows rather than silence. It answers whether the time went there compiled or interpreted.

The second question is the one a sampler cannot answer and the one that usually matters here: code the JIT refused is an order of magnitude slower than code it took, and nothing says so out loud.

Both channels attribute work through nupp.zone, so a sample or an abort carries the zone path that was open when it happened. Both are process-wide rather than per-coroutine, and at most one session of each kind runs at a time.

Neither is free. A sample session pays a timer interrupt, a stack walk and a table write at every interval; a trace session pays a callback at every abort, inside the compiler. Stop a session once the question it was opened for has an answer.

local profile = require("nupp.profile")

local session = profile.sample({intervalMs = 5})
render()
local report = session:stop("profile.out")
print(report.samples, report.stacks)

Module contents

Types

TypeKindDescription
AbortSiterecordOne place the JIT gave up, and how often it did.
SamplerecordOne distinct stack, and what landed on it.
SampleOptionstypeWhat profile.sample collects, and how much of it.
SampleReportrecordWhat a sample session saw, as SampleSession:stop returns it.
SampleSessionrecordA running sampler, as profile.sample returns it.
SessioninterfaceA running profiling session whose declaration chooses the report stop returns.
SeveritytypeHow much an abort is worth reading.
TraceOptionstypeWhat profile.trace counts.
TraceReportrecordWhat a trace session saw, as TraceSession:stop returns it.
TraceSessionrecordA running trace-abort collector, as profile.trace returns it.

Functions

FunctionKindDescription
samplefunctionStarts sampling.
SampleSession:pausemethodStops recording without ending the session.
SampleSession:resumemethodResumes recording.
SampleSession:stopmethodEnds the session and reports what it saw.
tracefunctionStarts collecting trace aborts.
TraceSession:pausemethodStops counting without ending the session.
TraceSession:resumemethodResumes counting.
TraceSession:stopmethodEnds the session and reports what it saw.

Types#

AbortSiterecord#

One place the JIT gave up, and how often it did.

A row of a TraceReport, built at stop.

record profile.AbortSite
    severity: profile.Severity
    count: integer
    reason: string
    location: string
    zonePath: string
end

Fields

NameTypeDescription
severityprofile.Severity

How much it is worth reading.

countinteger

Times this exact severity, reason, location and zone fired.

reasonstring

The reason, from jit.vmdef.traceerr. An unrecordable bytecode is rendered with the opcode's name.

locationstring

":" of the function being recorded when it aborted.

zonePathstring

The zone path that was open, "" when none was.

Samplerecord#

One distinct stack, and what landed on it.

A row of a SampleReport, built at stop. The five state counts sum to count.

record profile.Sample
    zonePath: string
    stack: string
    count: integer
    compiled: integer
    interpreted: integer
    cCode: integer
    collecting: integer
    compiling: integer
end

Fields

NameTypeDescription
zonePathstring

The zone path the samples were taken under, "" when none was open.

stackstring

The stack as dumpstack rendered it, ";" between frames, outermost first.

countinteger

Samples on this stack, in every VM state.

compiledinteger

Samples running compiled machine code.

interpretedinteger

Samples in the interpreter.

cCodeinteger

Samples inside a C function.

collectinginteger

Samples in the garbage collector.

compilinginteger

Samples inside the JIT compiler itself.

SampleOptionstype#

What profile.sample collects, and how much of it. Every field is optional.

type profile.SampleOptions = {
    --- Milliseconds between samples; 10 by default, which is 100 a second. Below about
    --- 10 the timer starts taking real time away from the thread it is measuring, so
    --- lower it for a short window and read the result knowing that it was paid for.
    intervalMs: integer?,

    --- How many frames to walk per sample; 16 by default. The walk is linear in this
    --- and it happens on the interrupted thread, so raise it only when a specific
    --- question needs the depth.
    stackDepth: integer?,

    --- Keep only the samples taken under a zone path starting with this, so
    --- "frame/render" reads as that subtree alone.
    ---
    --- Applied at `stop` rather than while sampling: narrowing it costs nothing at
    --- runtime, and widening it afterwards is not possible, because the prefix is fixed
    --- when the session starts.
    zone: string?,

    --- The module the program starts at, as a stack frame names it. Everything below
    --- the outermost frame from it is dropped.
    ---
    --- A profiler samples the whole stack it is embedded in, and what is under the
    --- program — the loader that read it, the pcall that guards it — is not the
    --- program. Naming its module cuts the report back to it.
    ---
    --- Frames read "<module>:<name>", so the module is the part to give. A stack with
    --- no frame from it is kept whole rather than emptied, and two stacks that differ
    --- only below the root become one, their counts summed.
    root: string?
}

SampleReportrecord#

What a sample session saw, as SampleSession:stop returns it.

tostring on it is the collapsed-stack text, so it prints and pipes directly.

record profile.SampleReport
    intervalMs: integer
    samples: integer
    stacks: integer
    text: string

    metamethod __tostring: function(self): string
end

Fields

NameTypeDescription
intervalMsinteger

The interval the session ran at, so the sample counts can be read as time.

samplesinteger

Samples recorded, after the zone filter.

stacksinteger

Distinct stacks they fell on.

textstring

One line per stack: semicolon-separated frames, a space, then the sample count. Ordered by count descending. Empty when nothing was sampled, which a short session and a zone prefix that matched nothing both produce.

SampleSessionrecord#

A running sampler, as profile.sample returns it.

Live until stop, and there is at most one at a time. Dropping the handle without stopping leaves the timer running for the rest of the process.

record profile.SampleSession is profile.Session
    associated type Report = profile.SampleReport
    intervalMs: integer
    zoneFilter: string?
    root: string?
    paused: boolean
    stopped: boolean
    aggregate: {[string]: {[string]: profile.Sample}}

    pause: function(self)
    resume: function(self)
    stop: function(self, filename: string?): self.Report
end

Methods

pause
pause: function(self)
Arguments
NameTypeDescription
?self
resume
resume: function(self)
Arguments
NameTypeDescription
?self
stop
stop: function(self, filename: string?): self.Report
Arguments
NameTypeDescription
?self
filenamestring?
Returns
TypeDescription
self.Report

Fields

NameTypeDescription
ReportassociatedDecl
intervalMsinteger

The interval it was started at.

zoneFilterstring?

The zone prefix stop will filter by, or nil for all of them.

rootstring?

The module stop will cut the stacks back to, or nil to keep them whole.

pausedboolean

Whether recording is suspended. The timer keeps firing.

stoppedboolean

Whether stop has run.

aggregate{[string]: {[string]: profile.Sample}}

Samples so far, by zone path and then by stack. Two levels rather than one joined key, so a sample taken in a zone that has not changed since the last one costs a single table lookup.

Sessioninterface#

A running profiling session whose declaration chooses the report stop returns.

Sampling and trace-abort sessions share this lifecycle. Generic helpers can use S.Report to preserve the concrete report chosen by a session declaration.

interface profile.Session
    associated type Report

    pause: function(self)
    resume: function(self)
    stop: function(self, filename: string?): self.Report
end

Methods

pause
pause: function(self)
Arguments
NameTypeDescription
?self
resume
resume: function(self)
Arguments
NameTypeDescription
?self
stop
stop: function(self, filename: string?): self.Report
Arguments
NameTypeDescription
?self
filenamestring?
Returns
TypeDescription
self.Report

Fields

NameTypeDescription
ReportassociatedDecl

Severitytype#

How much an abort is worth reading.

blacklist is always actionable: the code is demoted to the interpreter for the rest of the process. warn is a refusal that may or may not sit on a hot path. info is trace formation working as designed.

type profile.Severity = "blacklist" | "warn" | "info"

TraceOptionstype#

What profile.trace counts. Every field is optional.

type profile.TraceOptions = {
    --- Include the aborts that are ordinary trace formation rather than a refusal —
    --- leaving a loop, recursion, an inner loop. False by default; turn it on when the
    --- question is why a particular trace never formed.
    includeBenign: boolean?
}

TraceReportrecord#

What a trace session saw, as TraceSession:stop returns it.

tostring on it renders sites as RFC 4180 CSV, so it prints, sorts and diffs directly.

record profile.TraceReport
    durationSec: integer
    totalAborts: integer
    blacklisted: integer
    sites: {profile.AbortSite}

    metamethod __tostring: function(self): string
end

Fields

NameTypeDescription
durationSecinteger

Wallclock seconds the session was active, in whole seconds: it comes from os.time, so a session shorter than one reads as zero and dividing by it is the caller's problem.

totalAbortsinteger

Abort events recorded. Excludes the benign ones unless includeBenign was set.

blacklistedinteger

Blacklist events among them. Always actionable.

sites{profile.AbortSite}

One row per distinct severity, reason, location and zone. Ordered by severity, then by count descending.

TraceSessionrecord#

A running trace-abort collector, as profile.trace returns it.

Live until stop, and there is at most one at a time. Dropping the handle without stopping leaves the event hook attached for the rest of the process.

record profile.TraceSession is profile.Session
    associated type Report = profile.TraceReport
    includeBenign: boolean
    startedAt: integer
    paused: boolean
    stopped: boolean
    sites: {[string]: profile.AbortSite}
    totalAborts: integer
    blacklisted: integer
    callback: function(...: any)

    pause: function(self)
    resume: function(self)
    stop: function(self, filename: string?): self.Report
end

Methods

callback

The handler to hand back to jit.attach to detach it. Dropping the last reference to a handler does not remove it.

callback: function(...: any)
Arguments
NameTypeDescription
...any
pause
pause: function(self)
Arguments
NameTypeDescription
?self
resume
resume: function(self)
Arguments
NameTypeDescription
?self
stop
stop: function(self, filename: string?): self.Report
Arguments
NameTypeDescription
?self
filenamestring?
Returns
TypeDescription
self.Report

Fields

NameTypeDescription
ReportassociatedDecl
includeBenignboolean

Whether the benign trace-formation events are being counted.

startedAtinteger

os.time when the session started.

pausedboolean

Whether aggregation is suspended. The hook stays attached.

stoppedboolean

Whether stop has run.

sites{[string]: profile.AbortSite}

Aborts so far, by severity, reason, location and zone joined.

totalAbortsinteger

Aborts counted so far.

blacklistedinteger

Blacklist events among them.

Functions#

profile.samplefunction#

Starts sampling.

function profile.sample(options: profile.SampleOptions?): profile.SampleSession

Arguments

NameTypeDescription
optionsprofile.SampleOptions?

omitted samples every zone at 10 ms to a depth of 16

Returns

TypeDescription
profile.SampleSession

the handle whose stop produces the report

Raises

  • when a sample session is already running

profile.SampleSession:pausemethod#

Stops recording without ending the session. The timer keeps firing, at the cost of one test per sample, and what was recorded on either side of the pause is kept — which is how a benchmark leaves its setup out.

Idempotent.

function profile.SampleSession:pause()

Raises

  • once the session has stopped

profile.SampleSession:resumemethod#

Resumes recording. Idempotent.

function profile.SampleSession:resume()

Raises

  • once the session has stopped

profile.SampleSession:stopmethod#

Ends the session and reports what it saw.

function profile.SampleSession:stop(filename: string?): profile.SampleReport

Arguments

NameTypeDescription
filenamestring?

also write the collapsed-stack text there, replacing whatever was in it

Returns

TypeDescription
profile.SampleReport

the report, whose tostring is that same text

Raises

  • once the session has stopped, so it cannot be called twice

profile.tracefunction#

Starts collecting trace aborts.

function profile.trace(options: profile.TraceOptions?): profile.TraceSession

Arguments

NameTypeDescription
optionsprofile.TraceOptions?

omitted leaves the benign trace-formation events out

Returns

TypeDescription
profile.TraceSession

the handle whose stop produces the report

Raises

  • when a trace session is already running

profile.TraceSession:pausemethod#

Stops counting without ending the session. The hook stays attached, at the cost of one test per abort, and what was counted on either side of the pause is kept.

Idempotent.

function profile.TraceSession:pause()

Raises

  • once the session has stopped

profile.TraceSession:resumemethod#

Resumes counting. Idempotent.

function profile.TraceSession:resume()

Raises

  • once the session has stopped

profile.TraceSession:stopmethod#

Ends the session and reports what it saw.

function profile.TraceSession:stop(filename: string?): profile.TraceReport

Arguments

NameTypeDescription
filenamestring?

also write the CSV there, replacing whatever was in it

Returns

TypeDescription
profile.TraceReport

the report, whose tostring is that CSV

Raises

  • once the session has stopped, so it cannot be called twice