Skip to content

[Follow up] Time management after #8416 #8745

Description

@aldbr

Bug Description

/LocalSite/CPUTimeLeft is the CPU work left in the batch slot. The JobAgent publishes it every cycle, and three things read it: the Matcher, through the CPU work the CE advertises; the Watchdog, which counts it down; and the payload itself, when it is elastic and has to decide how much work to take on.

But the payload never gets all of it. Once the payload stops, the JobWrapper still has to upload the outputs and the logs, and the Watchdog reserves StopMargin (300 s by default) at the far end for exactly that — it stops the payload while that much is still on the clock. Nothing upstream of the Watchdog knows. So a job whose declared CPUTime just fits the slot is matched into it, and an elastic payload that sizes itself against /LocalSite/CPUTimeLeft commits to work it will not be allowed to finish. Both are then
stopped part-way.

Being stopped is itself lossy. The Watchdog's only response when the budget runs out is self.spObject.killChild(), i.e. SIGTERM escalating to SIGKILL. A payload killed mid-unit loses everything it had produced but not yet written, and because the job then fails, none of it is uploaded or recorded either.

There used to be a way out of that. The Watchdog still parses StopSigRegex, StopSigNumber, StopSigStartSeconds and StopSigFinishSeconds from the JDL, and used to signal the payload to wind down before killing it. That code is gone.

Finally, an application that does stop on a signal exits 128 + N — 130 for SIGINT, 138
for SIGUSR1. JobWrapper.postProcess treats any non-zero exit as an application error, so
a payload that did exactly what it was asked would be recorded as a failure.

Steps to Reproduce

  1. Configure a queue whose slots are comparable to the length of one job (or let a pilot fill
    until little is left).
  2. Submit a job whose JDL CPUTime is close to /LocalSite/CPUTimeLeft, or an elastic
    payload that reads /LocalSite/CPUTimeLeft and sizes its work from it.
  3. Watch it be matched, run, and be killed by the Watchdog with StopMargin still to go.

The elastic case is the one that shows the sizing error clearly, because the payload commits
to a specific amount of work up front. LHCb MC is the example we hit it with, but nothing
about the defect is VO-specific: any payload that sizes itself against the advertised slot
over-commits by StopMargin.

Expected Behavior

  • The CPU work advertised to the Matcher, and published in /LocalSite/CPUTimeLeft, is what
    a payload may actually consume — the post-processing reserve already deducted, once, by
    whoever publishes it.
  • A payload that knows how to wind down can be told to, early enough to finish its current
    unit of work and write its output, rather than only ever being killed.
  • A payload that stops when asked is not recorded as an application error.

Actual Behavior

Observed on an elastic LHCb MC job (job 1473012931), matched on
cycle 6 of 10 with 1357 s of wall clock left in the slot:

CPUTimeLeft      = 37878 (normalized units)   CPUNormalizationFactor = 27.9
CPUTime          = int(37878 / 27.9)                  = 1357 s
eventsToProduce  = int(floor(1357 * 27.9) / 154)      = 245
willProduce      = int(245 * 0.75)                    = 183   # VO safety factor

The payload was sized for 183 units against 1357 s, but the Watchdog only ever intended to
let it have 1057. It produced 150, was killed, and the 4.9 MB output file it had written was
never uploaded. The job is Failed, so it also never reaches the Bookkeeping — which means
failures of this kind cannot feed back into the per-unit cost estimate that sized them.

Environment

  • DIRAC integration
  • Payload: elastic, sizes its own work from /LocalSite/CPUTimeLeft

Relevant Log Output

Job has reached the CPU limit of the queue    wallClockLeft=297s
'FinalMinorStatus': 'Job has reached the CPU limit of the queue',
'ExecTime': 1065, 'ProcessedEvents': 0

ProcessedEvents: 0 despite 150 having been produced: the payload was killed before it could
report them.

Additional Context

Proposed fix, in two parts. They are independent by construction and can be reviewed
separately:

  • fix: job wrapper status now that the watchdog kills the payload #8528: report a watchdog-stopped payload for what it is, rather than as
    "No outputs generated from job execution", and treat 128 + N as a clean exit when N
    is the signal the Watchdog itself sent. The second half is a no-op until the graceful stop
    exists (stopSigSent is never set today), so this can go first on its own.
  • next PR: deduct StopMargin once, in JobAgent.initialize(), so the Matcher and
    the payload both see a budget they can actually spend; and restore the graceful stop on
    that same budget, with StopSigRegex matching the command line again as it did before
    0e67f781de.

Related:

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions