Tracking Cron Job Duration: Catch Slow Runs Before They Overlap

To track cron job duration, record when each run starts and finishes, keep those numbers in a history that outlives the run, and alert when a run crosses a limit set well before the point where it would collide with the next one. Cron has no runtime setting, and of the common cron daemons only cronie 1.5.6 and later logs the end of a job by default. A job that grows from 10 minutes to 3 hours fails no check on the way. It exits 0 every night until the night it runs into its own next start, or into the job that reads its output.

Why Run Time Is Worth Watching#

A run that gets longer each week fails nothing until the growth hits a limit:

• Overlap. cronie and Debian's cron start a job at its scheduled minute whether or not the previous run has finished (cronie job.c). Two copies then compete for the same rows and locks, and both slow down.
• Downstream deadlines. A 01:00 import that a 04:00 report reads has a three-hour budget, whatever its own schedule allows.
• Timeouts. A job under a time limit eventually reaches it, and that night it finishes nothing.
• Cost. A longer run holds its machine, connections, and locks longer, and anything billed by run time costs more.

Cron, systemd, and Kubernetes Record Part of It#

Cron Logs Starts, and Sometimes Ends#

cronie has logged CMDEND when a job finishes since 1.5.6 (commit); RHEL 8's cronie 1.5.2 predates it. On Fedora and RHEL the unit is crond:

journalctl -u crond --since yesterday | grep -E 'CMD(END)? \(/opt/import/'

Oct 24 01:00:01 db1 CROND[48211]: (etl) CMD (/opt/import/nightly-import-monitored.sh)
Oct 24 03:07:44 db1 CROND[48210]: (etl) CMDEND (/opt/import/nightly-import-monitored.sh)

The PIDs differ because CMD is logged by the process that becomes the job's shell and CMDEND by the cron process that waited for it (do_command.c), so pair the lines by command and time.

Debian's cron logs only starts by default. Its -L option takes a sum: 1 logs starts, 2 ends, 4 failed jobs, and 8 adds the job's PID to each line, so 15 selects all four (cron(8)). Set EXTRA_OPTS='-L 15' in /etc/default/cron, which cron.service reads (cron.service), restart cron, and read the lines with journalctl -u cron.

BusyBox crond 1.37 logs each start and nothing at the end (crond.c). It also won't start a crontab line again while its previous run is still going; it logs process already running and skips that run. None of these lines carries input size, and they last only as long as the journal keeps them.

systemd Keeps the Last Run, and the Journal Keeps More#

For a job run by a systemd timer, the service records ExecMainStartTimestamp when its main process is created and ExecMainExitTimestamp when its exit is detected (org.freedesktop.systemd1(5)). Their Monotonic variants are microsecond counters that a clock change can't skew. After a run finishes:

systemctl show nightly-import.service \
  -p ExecMainStartTimestampMonotonic -p ExecMainExitTimestampMonotonic |
  awk -F= '{ t[$1] = $2 }
    END { printf "%ds\n", (t["ExecMainExitTimestampMonotonic"] - t["ExecMainStartTimestampMonotonic"]) / 1000000 }'

These cover only the last run. InactiveExitTimestamp and InactiveEnterTimestamp bracket the whole activation, including ExecStartPre= and ExecStartPost= commands.

For history, use the journal. When a unit stops, systemd logs what it consumed, and from systemd 259 the line also gives the wall-clock time since the unit left the inactive state (commit):

journalctl -u nightly-import.service --since "30 days ago" | grep Consumed

Oct 24 03:07:44 db1 systemd[1]: nightly-import.service: Consumed 4min 12.301s CPU time over 2h 7min 43.018s wall clock time, 812.4M memory peak.

Earlier versions print only the CPU part. systemd logs the line at info level only when the run crossed a small threshold, such as more than one second of CPU time; below that it's a debug message, which isn't logged at the default level (unit.c).

Kubernetes Records Start and Completion#

A Job's .status.startTime is when the Job controller started processing it. .status.completionTime is set when the Job finishes successfully, and only then (Kubernetes 1.37 API reference). The start comes before pod scheduling and image pulls, so the figure is longer than the container's own work. kubectl get jobs prints the difference as DURATION, and for a Job without a completion time, which includes a failed one, it counts up to now (printers.go). A failed Job ended at the lastTransitionTime of its Failed condition.

This prints the seconds each retained successful Job of a CronJob took:

kubectl get jobs -o json | jq -r '
  .items[]
  | select(any(.metadata.ownerReferences[]?; .kind == "CronJob" and .name == "nightly-import"))
  | select(.status.completionTime != null)
  | [.metadata.name, ((.status.completionTime | fromdateiso8601) - (.status.startTime | fromdateiso8601))]
  | @tsv'

"Retained" is the catch: a CronJob keeps three successful Jobs and one failed Job by default (successfulJobsHistoryLimit, failedJobsHistoryLimit in types.go), too few for a trend.

Measure Every Run in the Wrapper#

The record that works everywhere is one the job writes itself. Two date +%s calls around the command give wall-clock seconds with GNU or BusyBox date. In Bash, SECONDS counts whole seconds since the shell started and EPOCHREALTIME (5.0+) has microseconds (Bash manual). All of these follow the system clock, so a clock step mid-run skews them; Bash 5.3's BASH_MONOSECONDS reads the monotonic clock (Bash NEWS).

Wall-clock time alone doesn't say whether the job was working or waiting. GNU time 1.9, the time package in Debian 13 and Fedora, adds CPU time and memory:

/usr/bin/time -a -o /var/lib/nightly-import/time.log -f '%e %U %S %M %x' /opt/import/nightly-import.sh

Each run appends elapsed wall-clock seconds (%e), user and system CPU seconds (%U, %S), peak resident memory in kilobytes (%M), and the exit status (%x); -v labels every field (GNU time manual). -o keeps the report out of the job's stderr, which cron would mail. GNU time exits with the command's status, or 128 plus the signal number if a signal killed it (time.c), so it doesn't hide a failure. Use the full path: in a bash script, a bare time is the shell's reserved word, which reports the three timings in the format set by TIMEFORMAT and has none of these options.

Keep a History and Read It in Percentiles#

Store one line per run: finish time, duration, exit status, and a measure of input size such as rows processed. A CSV on the job's host is enough, and the wrapper further down writes one. Hosts running node_exporter can also publish a last-duration gauge through the textfile collector, as monitoring cron jobs with Prometheus sets up. CronRadar's run history shows each run's duration, for 30 days on Free and 90 on Grow, which can be shorter than the trend you need.

Read the history in percentiles, not averages:

• The median (p50) is the trend line. It moves when the typical run slows, and one bad night doesn't move it.
• The p95 is a bad but normal run, and the base for a relative threshold.
• The maximum is what collides with the next run. A max that climbs while the median stays flat means some runs hit something, such as a lock or a slow dependency, rather than steady growth.
• The mean blurs both: one 3-hour run among 29 ten-minute runs lifts it to about 16 minutes.

Compare like with like. A month-end or quarter-close run has more to process by design, and a Monday run may carry the weekend; compare those runs with each other, or keep them out of the baseline.

This prints the median, p95, and max of successful runs per month from the CSV, the view in which a slow creep is plain:

awk -F, '$3 == 0 { print substr($1, 1, 7), $2 }' /var/lib/nightly-import/durations.csv |
  sort -k1,1 -k2,2n |
  awk '
    function rank(p,  r) { r = int(p * n); if (r < p * n) r++; return r }
    function report() { if (n) printf "%s runs=%d p50=%ds p95=%ds max=%ds\n", m, n, d[rank(0.5)], d[rank(0.95)], d[n] }
    $1 != m { report(); m = $1; n = 0 }
    { d[++n] = $2 }
    END { report() }'

Set Two Limits: One From the Schedule, One From the Baseline#

An absolute limit comes from the schedule. Find the first thing the job can collide with: its own next start, or the first job that reads its output. A 01:00 import read at 04:00 has three hours. Put a hard stop a margin below that, a 150-minute timeout here, so a killed run's cleanup and alert land before the report starts. Put an alert well below the hard stop, at 90 minutes, so the first night that crosses it leaves weeks to fix the growth rather than minutes.

A relative limit catches the change while it's small: alert when a run takes more than twice the p95 of the last 30 successful runs. For a 10-minute job that fires at about 20 minutes, while the cause is likely still a recent change you can find. It needs a stored baseline and some arithmetic. The job, Prometheus, or another store you run has to do that; CronRadar compares each reported value with a fixed number.

Both alerts fire when the slow run finishes, because a run still in progress hasn't reported a duration. Ending a run at a limit is the timeout's job; cron job timeouts covers signals, child processes, and cleanup.

Alert on Slow Runs With CronRadar#

CronRadar records the duration of a run that reports start and then complete. It has no duration or slow-run alert setting. To alert on a slow run, the job reports its own duration as a bounded outcome, and the monitor checks it against an expectation such as duration_seconds <= 5400.

There is no CronRadar SDK for shell scripts and no auto-discovery for cron, so each job reports with its own HTTP check-ins. This wrapper sends start, runs the import under GNU coreutils timeout, appends the run to the CSV, and reports complete with three outcomes: duration, rows loaded, and duration as a percentage of the p95 of the previous 30 successful runs. The import writes its row count to /var/lib/nightly-import/rows.

#!/bin/sh
# /opt/import/nightly-import-monitored.sh: run the import under a time limit,
# log its duration, and report duration and row count to CronRadar.
key=nightly-import
url="https://cron.life/api/v1/ping/$key"
run_id="$key-$(date +%s)-$$"
state=/var/lib/nightly-import
history="$state/durations.csv" # finished_at,duration_seconds,exit_code,rows

checkin() {
  event=$1
  shift
  curl --fail --silent --show-error --max-time 5 --output /dev/null \
    --request POST --get --user "$CRONRADAR_API_KEY:" \
    --data-urlencode "schedule=0 1 * * *" \
    --data-urlencode "gracePeriod=300" \
    --data-urlencode "run_id=$run_id" \
    "$@" "$url/$event" || true
}

# Nearest-rank p95 of the last 30 successful runs, before this run is added.
p95=$(awk -F, '$3 == 0 { print $2 }' "$history" 2>/dev/null | tail -n 30 | sort -n |
  awk '{ d[NR] = $1 } END { if (NR >= 10) { r = int(0.95 * NR); if (r < 0.95 * NR) r++; print d[r] } }')

checkin start
rm -f "$state/rows"
started=$(date +%s)
timeout -k 2m 150m /opt/import/nightly-import.sh
rc=$?
duration=$(($(date +%s) - started))

rows=$(cat "$state/rows" 2>/dev/null)
case "$rows" in
  '' | *[!0-9]* | 0?*) rows= ;; # missing, or not a plain whole number
esac
echo "$(date -u +%Y-%m-%dT%H:%M:%SZ),$duration,$rc,$rows" >>"$history"

case "$rc" in
  0) ;;
  124)
    checkin fail --data-urlencode "message=nightly-import.sh hit its 150-minute timeout"
    exit "$rc"
    ;;
  *)
    checkin fail --data-urlencode "message=nightly-import.sh exited with code $rc after ${duration}s"
    exit "$rc"
    ;;
esac

outcomes="\"duration_seconds\":$duration"
[ -n "$rows" ] && outcomes="$outcomes,\"rows_processed\":$rows"
[ "${p95:-0}" -gt 0 ] && outcomes="$outcomes,\"duration_vs_p95_pct\":$((duration * 100 / p95))"

curl --fail --silent --show-error --max-time 5 --output /dev/null \
  --request POST --user "$CRONRADAR_API_KEY:" \
  --header "Content-Type: application/json" \
  --data "{\"outcomes\":{$outcomes}}" "$url/complete?run_id=$run_id" || true
exit 0

Schedule it as 0 1 * * * /opt/import/nightly-import-monitored.sh with CRONRADAR_API_KEY in its environment, on a host whose cron runs in UTC; CronRadar reads schedule in UTC. Each request gives up after five seconds and ignores errors, and the wrapper exits with the job's own status. A fail alerts immediately. Because start carries the schedule, the first run creates the monitor and a later run recreates a deleted one; schedule and gracePeriod apply only when a check-in creates the monitor, so change them afterwards in the monitor's settings. The same run_id on start and complete pairs the two even when runs overlap. The JSON request leaves out --get, which would move its data into the query string (curl).

Then, in the monitor's settings under Outcome checks, configure the expectations:

The API reference sets the body's rules: at most five values; keys that start with a lowercase letter and use only lowercase letters, digits, and underscores, up to 64 characters; values that are finite numbers or booleans. Keys without an expectation are accepted but not stored, which is one reason rows_processed gets a check: it keeps each run's row count beside its duration. A configured key that is omitted fails its check. Add the ratio check once the CSV holds 10 successful runs; from then on, a lost or moved history file shows up as a missing value. The next run within its limits closes the incident with a recovery alert.

Test the body once by hand. CronRadar rejects a body it can't accept, such as one with a sixth value, an uppercase key, or a string value, with a 400 and records no completion. The next night's start still arrives on time, so that can repeat without an alert. Run the complete request once with --fail-with-body instead of --fail, and without || true, to see the response. When a job succeeds but does nothing covers choosing outcome floors for counts.

Slow Is Not Stuck#

A slow run finishes, so its duration exists and an outcome check can judge it. A stuck run never finishes and reports nothing to judge.

CronRadar's stuck detection needs the start check-in. Every check-in, including start, moves the expected time to the job's next scheduled occurrence. If that time plus the grace period passes while the last event was a start with no complete or fail, the monitor goes critical as stuck. The window belongs to the job, not the run: the next run's start resets it, so a hang is caught only when the job then goes silent. There is no per-job maximum-runtime setting.

Without a timeout, a hung nightly import under cronie or Debian's cron is never flagged as stuck: the next night's run starts beside it and checks in. With flock -n in front of the wrapper, the next night's run exits without checking in, and the hang is flagged a day plus the grace period after it began; preventing overlapping cron jobs walks through that timeline. The timeout in the wrapper turns a hang into a fail the same night.

When a Job Gets Slow, Find What Grew#

Divide duration by input to see which kind of slow it is:

awk -F, '$3 == 0 && $4 > 0 { printf "%s %.2f s per 1k rows\n", substr($1, 1, 10), $2 * 1000 / $4 }' \
  /var/lib/nightly-import/durations.csv | tail -n 30

• Flat cost per row, rising totals: the data grew. Process only what changed since the last successful run, using a high-water mark such as an updated_at column, or split the work into batches.
• Rising cost per row: each row got more expensive. For a database job, run the slow query under EXPLAIN (ANALYZE, BUFFERS) and look for sequential scans of tables that have grown and row estimates far from the actual counts (PostgreSQL 18). The auto_explain module logs the plan of any statement slower than auto_explain.log_min_duration (auto_explain), and an administrator can load it for only the job's role with ALTER ROLE ... SET session_preload_libraries (PostgreSQL 18).
• Wall-clock time far above CPU time: the job is waiting. Three hours of wall-clock time with four minutes of CPU means a night spent on a database, a lock, or a remote API. Log how long each external call takes, and look for lock waits and rate limiting.
• Slow only on nights that overlap: two copies are contending. Add a lock first, then measure again.

Frequently Asked Questions#

How do I see how long a cron job took?#

On cronie 1.5.6 or later, compare the job's CMD and CMDEND lines in the journal; Debian's cron logs job ends only with its -L option. For a systemd timer, systemctl show has the last run's timestamps, and kubectl get jobs shows a Kubernetes Job's DURATION. To compare runs over time, measure in a wrapper and log every run.

Can CronRadar alert when a cron job runs too long?#

Not from a duration setting, because there isn't one. The job reports its duration as an outcome on complete, and a configured expectation such as duration_seconds <= 5400 opens an incident when a run exceeds it, once that run finishes. To stop a run at a limit, run the job under a timeout and report fail, which alerts immediately.

What's the difference between a slow cron job and a stuck one?#

A slow run finishes late, so its duration can be checked. A stuck run never finishes. CronRadar flags it only when the job's next scheduled time plus the grace period passes with the last event still a start, and the next run's start resets that window, so a timeout inside the job is the dependable catch.

How do I stop a slow cron job from overlapping the next run?#

Run it under a lock such as flock -n, so a new run exits while the old one holds the lock, and give it a timeout shorter than the gap between runs. Then fix the growth: a job that keeps getting skipped or killed isn't doing its work.

How do I track cron job duration over time?#

Append each run's duration, exit status, and input size to a log or CSV, or publish a last-duration gauge to Prometheus. Read it per week or month as median, p95, and maximum: the median shows creep, and the maximum shows what will collide.