Pular para o conteúdo principal

Job statistics

Per-stage elapsed-time statistics on the dashboard — what is collected, how each number is calculated, and how to read them when processing feels slow.

At a glance​

QuestionAnswer
Where do the numbers live?The operational store — one row per completed job. They survive restarts, and in a cluster every instance shows the same deployment-wide figures.
How do I turn it on or off?Statistics:Enabled (default true). When false, nothing is recorded and the dashboard panel disappears.
What is measured?Four stages per job — queue wait, signing, verification, output creation — plus a total (their sum).
What is not measured?The two human waits: the Lacuna Signer AwaitingSigner wait and the AwaitingApproval wait. Both are deliberately excluded — see below.
Where do I see it?The Dashboard home page, "Processing performance" panel, refreshed on the normal dashboard poll (Dashboard:PollIntervalSeconds) — and, for one job, the Processing time section on its job page (see below).
How do I clear it?Clear Jobs moves a deployment-wide reset marker and deletes every job with its timing row — see Resetting the panel.
Want durable history outside the product?Scrape /api/metrics — bulksigner_signing_duration_seconds is the external record (see REST API).
Changed in 2.0.0

The numbers used to live in process memory and reset on every restart. They are now rows in the operational store, which is what makes the panel survive a restart and describe a whole cluster rather than whichever instance answered. One card was retired in the move — see "Max throughput/sec" is gone.

What is collected​

For every job the pipeline times four stages, measured with a monotonic clock at exact code boundaries:

StageStarts atEnds at
Queue waitJob entered the queue (QueuedAt)Worker picks the job up (transition to Processing)
SigningLocal: just before the signature call. Remote: just before document creation (dispatch) and just before the signed download (poll)Immediately after each of those calls returns
VerificationJust before the signature is verifiedImmediately after it returns (skipped jobs contribute no sample)
Output creationEncrypt (if enabled) + write to processing/After promote-to-output/ and delete-original

Total = queue wait + signing + verification + output. This is the active machine time the job cost end to end. It is not the created-to-completed wall clock for a remote job, because that would include the human-signing wait.

When the job reaches Completed, those four durations are written to the store as one row, alongside the completion timestamp and whether the job was signed Local or Remote (Lacuna Signer). Every figure on the panel is an aggregate over those rows.

A stage that did not happen is stored as null, never as zero: a job whose profile sets Verify = false has no verification sample, so it neither drags that stage's average down nor inflates its count. The total still sums the stages that did happen.

Where the numbers live, and what that buys​

One row per completed job, in the same database as the jobs themselves, cascaded away with its job. Three consequences worth knowing:

  • They survive a restart. There is no "since boot" window any more. The caption says how many jobs have completed and since when, where "since when" is the last reset if there has been one and otherwise the oldest completion still on record.
  • Every instance shows the same numbers. Under cluster mode the dashboard you reach is whichever instance the load balancer picked, and the panel describes the whole deployment rather than that instance's share of it.
  • They grow with completed jobs and nothing else. A handful of numeric columns per job, bounded by a job count the store already carries.

A job in flight is still measured in process memory and only becomes a row when it completes. So a host killed mid-job loses that job's partial timings: the job records nothing rather than something wrong, and every job that finished before the restart is unaffected.

What each dashboard metric means​

The "Processing performance" panel shows:

MetricMeaning
Avg job timeMean of the per-job total (active time).
Avg signingMean signing-stage time. For remote jobs this is dispatch + download, not the wait between them.
Avg verificationMean verification-stage time. Jobs that skip verification (Verify = false) are not counted, so this average reflects only jobs that actually verified.
Throughput (last min)Completions in the trailing 60 seconds, expressed per minute — a responsive "right now" rate.
Total processing time — Min / Avg / MaxThe extreme and mean per-job totals, in hh:mm:ss.fff form. Min and Max are single-job observations, useful for spotting outliers.
Average by stage — Queue wait / OutputMean intake-backlog time and mean output-materialisation time (encryption + promote).
By method — Local (n) / Remote (n)Mean total for locally-signed vs Lacuna-Signer jobs, with the sample count in parentheses.
LifetimeCompleted jobs ÷ the window the rows cover, expressed per minute.
Slowest jobThe single completed job behind Max — named, with its total in hh:mm:ss.fff and when it completed, linked to its page so you can see what was slow about it. Computed over the same rows as everything above, so a reset moves it too. Absent when nothing has completed since the reset.

The caption shows how many jobs have completed and the start of that window.

One more card sits in the stat grid at the top of the page rather than in this panel, because it is not a statistic: Running for (Longest running when Pipeline:MaxConcurrency > 1) shows the in-flight job the pipeline has held the longest, ticking live once a second, linked to its page. It is measured from the job's most recent pickup — a job released from approval is picked up twice, and the human's deliberation in between is not running time — or, on a job back from Lacuna Signer, from the download that brought it back, since a remote job's pickup may be days old. It is present only while something is in flight, and does not depend on Statistics:Enabled.

Durations render in two forms: rounded prose on the stat cards (2 min 14 sec, 3.4 sec, 421 ms) and fixed hh:mm:ss.fff in the min/avg/max row (00:00:03.421). A stage with no samples yet shows an em dash (—). Durations are stored to the millisecond, which is exactly the finest resolution either rendering shows.

"Max throughput/sec" is gone​

There used to be a card showing the busiest single wall-clock second observed. It measured one process's lifetime, so under a cluster it would have described one instance's luck, and there is no honest way to reconstruct a deployment-wide equivalent from completion timestamps. It was retired rather than approximated. "Throughput (last min)" answers the question it was mostly being read for, and bulksigner_signing_duration_seconds on /api/metrics is unchanged and still the external record.

One job's own numbers​

The row the panel aggregates is also one job's breakdown, and the job's page (/jobs/{id}) shows it in a Processing time section, in one of two shapes:

  • A completed job shows the four stages and the total exactly as they were recorded, in hh:mm:ss.fff, beside when the pipeline picked the job up and when it completed. The Output stage is the post-processing — encryption, promotion to output/ and the original's deletion. A stage that did not happen — verification on a profile with Verify = false — reads skipped, never 00:00:00.000, the same distinction the panel's averages keep. The caption says what "total" means here: for a Lacuna Signer job it is the document's creation and download and never the wait for the signer, and for either method the wait for an approver is not in it. So on a remote or approval-gated job, the total is far smaller than the gap between the timeline's first and last entries — and that difference is the exclusion below.
  • A job in flight (Processing or Verifying) shows how long the pipeline has held it, live — the same figure, and the same rule, as the dashboard's Running for card. The stage breakdown does not exist yet; it is written when the job completes.

Every other job shows no section: a failed, canceled or expired job records no timings (there is one row per completed job), and a completed job with no row — statistics were off, or the host died mid-job — shows nothing rather than a row of dashes. Statistics:Enabled = false hides the stage breakdown along with the panel; the live figure on a job in flight is not a statistic and stays. An approver who can open the job page sees the section too — it is a record about the job, not a capability.

What the section deliberately does not offer: grouping or filtering by profile, folder or date range; a failed job's elapsed time until failure or error counts by type; per-attempt timings (a retry is a new job, and is timed as one); a split of the Lacuna Signer signing span into create and download (the two are summed into Signing); and median, percentile or "ten slowest" views. For analysis of that kind, use the bulksigner_signing_duration_seconds histogram on /api/metrics.

How elapsed time is calculated​

Timing uses a monotonic clock source, unaffected by wall-clock adjustments (NTP steps, DST), so a clock change mid-job cannot produce a negative or wildly wrong span. Each measured span wraps exactly one operation; negative spans from clock edge cases are floored at zero before they are stored.

A job's partial timings are held in an in-flight entry keyed by job id while it processes. The remote path spans two workers — one records the dispatch span, the other records the download, verify and output spans onto the same entry once the document comes back, on the same instance, because a job is owned by one instance from pickup to terminal status. On successful completion the entry becomes a row; on any failure, cancel or timeout it is discarded, so a job that never finishes neither leaks memory nor skews the averages.

Why the human waits are excluded​

A Lacuna Signer document can sit in AwaitingSigner for hours or days while a person signs it (Signer:TimeoutHours defaults to a full week). If that wait were folded into "average signing time", a single slow human would dominate every number and the panel would stop telling you anything about system performance. So the wait between dispatch and download is never timed. To see how long documents are parked awaiting signature, use the AwaitingSigner count on the dashboard, the per-job AwaitingSignerSince timestamp, or the bulksigner_jobs_awaiting_signer metric — see Lacuna Signer integration.

The AwaitingApproval wait is excluded for the same reason, and more bluntly: parking discards the job's in-flight entry outright, so a parked job contributes nothing at all. To see how long jobs have been parked, use the "Awaiting approval" card and the per-row wait duration on /jobs, the per-job AwaitingApprovalSince timestamp, or the bulksigner_jobs_awaiting_approval metric — see Approvals.

A released job is measured from the release, not from when the file arrived. Once the quorum is met the job re-enters the queue and is picked up fresh, opening a second timing entry — and that entry's queue wait is anchored on QueuedAt, which the release re-stamps. Without that anchor the second pickup would measure from CreatedAt and quietly re-import the whole approval wait the exclusion above exists to keep out. So a job that waited two days for a quorum and then signed in 400 ms contributes a 400 ms job, which is the honest reading of what the pipeline did.

Resetting the panel​

Running Clear Jobs records a deployment-wide reset marker: from then on the aggregates count only jobs that completed after it. It takes effect on every instance at once, because the marker is a row rather than a variable in one process.

Three things follow:

  • The marker itself deletes nothing — the jobs going does. A timing row is removed only when its job is, through the foreign key. Since 2.9.0 Clear Jobs deletes every job, so the rows it hides are normally gone with their jobs anyway; deleting a single job from the Jobs page likewise takes its timings with it.
  • A job that completes after the clear counts from the marker. The marker covers the job that was enqueued while the clear was running: its row lands after the marker and counts.
  • The reset rolls back with the clear. The marker moves inside the clear's transaction, so a clear that fails leaves the panel exactly as it was.
Changed in 2.9.0

Until 2.9.0 Clear Jobs spared unfinished jobs, and the marker was what let such a job keep its half-finished measurement and count once it completed. Clear Jobs now deletes every job whatever its status, so there is no surviving job for the marker to protect.

The Prometheus histogram is a monotonic counter and is not affected by any of this.

Using the statistics to diagnose slow processing​

Read the stage split to localise a slowdown:

SymptomLikely causeWhere to look next
Queue wait high, everything else normalBacklog — files arrive faster than the worker drains themRaise Pipeline:MaxConcurrency (mind the PKCS#11 / Windows-store caveat in Configuration); check the Queued count
Signing high on Local jobsSlow certificate source — HSM/PKCS#11 round-trips, a contended token at MaxConcurrency > 1, or Key Vault latencyCertificates; consider keeping token-backed profiles at MaxConcurrency = 1
Signing high on Remote jobsSlow Lacuna Signer API (create/download), not the human waitbulksigner_signer_api_errors_total, network to the Signer endpoint; Lacuna Signer integration
Verification highLarge artifacts or slow revocation/chain checks during verifyProfile Verify settings; artifact sizes
Output highEncryption cost or slow output/ storage (network share, slow disk)Encryption; the output/ volume
Max ≫ AvgA few outliers (large files, a transient stall)Sort recent jobs by size; check logs around the spike
Throughput (last min) ≪ LifetimeA current stall or pausePipeline pause state; the live "In progress" / "Slots busy" card

Because the rows persist, the panel is now a trend signal as well as a live one — the window it covers is however long you have been keeping completed jobs. For analysis outside the product, scrape the Prometheus endpoint into Grafana; the bulksigner_signing_duration_seconds histogram is the durable counterpart, and it is unaffected by resets.

In a cluster, read the panel and /api/metrics differently

The panel is deployment-wide because it aggregates rows. /api/metrics is per process and a scrape reaches an arbitrary instance, so a per-instance gauge read as a fleet total under-reports — see High availability.

Configuration​

KeyTypeDefaultEnv overrideNotes
Statistics:EnabledbooltrueStatistics__EnabledMaster switch. false makes the collector a no-op, writes no row, and hides the dashboard panel. Turning it off does not delete rows already recorded — turning it back on shows them again.

Next: Telemetry — optional Application Insights integration. Previous: Dashboard.