[Follow up] Time management after #8416
- Dominant language
- Python
- Stars
- 126
- Forks
- 191
- Avg merge
- 1d 13h
- Merged PRs (30d)
- 33
Description
## 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
```shell
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:
- #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:**
- #8416 the single-writer design this relies on: the JobAgent publishes
`/LocalSite/CPUTimeLeft` and everyone else reads it, because a containerised payload cannot
reach the batch system to recompute it.
- #8346 draining pilots; its second point, jobs that produce nothing when stopped
and are hard to tell from real failures, is the same complaint from the other end.
Contributor guide
Assessment
This issue has not been assessed yet.