Logging, Retries, Timeouts, and Idempotency

1. Automation needs evidence, not decorative output

A log record should help answer what operation ran, when it ran, which target it affected, which attempt or phase failed, and what status was returned. Logs belong on standard error when standard output is reserved for data. Stable key-value records are easier to search than prose and remain readable without a log platform.

flowchart TD
  D["Desired state"] --> I["Inspect current state"]
  I --> C{"Already converged?"}
  C -- yes --> N["Log no-op and return success"]
  C -- no --> A["Apply bounded operation"]
  A --> R{"Result class"}
  R -- success --> V["Verify resulting state"]
  R -- transient --> B["Backoff with jitter and retry"]
  R -- permanent --> F["Log evidence and fail"]
  B --> A
  V --> C2{"Verified?"}
  C2 -- yes --> S["Log change and return success"]
  C2 -- no --> F

log() {
  local level=$1 message=$2
  shift 2
  printf 'time=%q level=%q component=%q message=%q' \
    "$(date --iso-8601=seconds)" "$level" "${PROGRAM_NAME:-automation}" "$message" >&2

  local pair
  for pair in "$@"; do
    printf ' %s' "$pair" >&2
  done
  printf '\n' >&2
}

log INFO 'starting reconciliation' "target=$target" "run_id=$run_id"
log ERROR 'remote request failed' "status=$status" "attempt=$attempt"

Do not log secrets, authorization headers, private keys, or full environment dumps. Redaction after a leak is unreliable. Decide which fields are safe before formatting the record.

2. Every external dependency needs a time budget

A command without a timeout can block a CI runner, lock, deployment, or incident workflow indefinitely. GNU timeout starts a command, sends a signal after the duration, and normally returns 124 when the time limit is reached. Some clients also provide connection and total timeouts; use both when they protect different phases.

run_with_deadline() {
  local duration=$1
  shift

  if timeout --signal=TERM --kill-after=5s "$duration" "$@"; then
    return 0
  fi

  local status=$?
  if (( status == 124 )); then
    printf 'command timed out after %s: %q\n' "$duration" "$1" >&2
  else
    printf 'command failed with status %d: %q\n' "$status" "$1" >&2
  fi
  return "$status"
}

run_with_deadline 20s curl \
  --connect-timeout 5 \
  --max-time 18 \
  --fail --silent --show-error \
  https://example.com/health

A timeout is not cancellation proof. The child may have started remote work before the local process is terminated. Design the remote operation around idempotency keys, request identifiers, or post-timeout state inspection.

3. Retry only failures that may become success

Authentication errors, malformed input, missing files, policy rejection, and deterministic validation failures do not improve with repetition. Connection resets, rate limits, temporary name-resolution failures, and unavailable services may be transient. Classify the failure before retrying and cap both attempts and elapsed time.

For exponential backoff, a common delay before attempt n is:

retry() {
  local max_attempts=$1 base_delay=$2 max_delay=$3
  shift 3

  local attempt=1 status delay jitter
  while true; do
    if "$@"; then
      return 0
    fi
    status=$?

    # The caller should classify permanent statuses before using retry.
    if (( attempt >= max_attempts )); then
      return "$status"
    fi

    delay=$(( base_delay * (2 ** (attempt - 1)) ))
    (( delay > max_delay )) && delay=$max_delay
    jitter=$(( RANDOM % (delay + 1) ))

    log WARN 'transient failure; retrying' \
      "status=$status" "attempt=$attempt" "sleep_seconds=$jitter"
    sleep "$jitter"
    (( attempt += 1 ))
  done
}

RANDOM is sufficient for scheduling jitter, not cryptography. For HTTP APIs, honor server-provided retry information where appropriate and ensure the operation is safe to repeat.

4. Idempotent automation converges to desired state

An idempotent operation can be repeated without producing additional unintended changes once the desired state is reached. “Append this line” is generally not idempotent. “Ensure exactly one matching configuration entry exists” can be. “Create a user” fails on the second run; “ensure the account exists with these properties” inspects and reconciles.

ensure_line() {
  local file=$1 expected=$2 tmp
  [[ -e $file ]] || : > "$file"

  if grep -Fxq -- "$expected" "$file"; then
    log INFO 'configuration already converged' "file=$file"
    return 0
  fi

  tmp=$(mktemp -- "${file}.tmp.XXXXXXXX") || return
  trap 'rm -f -- "$tmp"' RETURN

  awk -v expected="$expected" '$0 != expected { print } END { print expected }' \
    "$file" > "$tmp"
  chmod --reference="$file" "$tmp" 2>/dev/null || true
  mv -f -- "$tmp" "$file"
  trap - RETURN
  log INFO 'configuration updated' "file=$file"
}

The temporary file and rename pattern prevents readers from observing a partially written file on the same filesystem. It does not replace locking when multiple writers may race. When concurrent mutation is possible, use flock, a service API, or another ownership mechanism.

5. Hands-on lab: build an observable idempotent reconciler

The lab simulates a transient dependency, retries with bounded delay, and ensures one configuration line exists exactly once. Running the script repeatedly should produce a no-op after convergence.

lab="$HOME/devops-academy/linux/chapter15/lesson03"
rm -rf "$lab"
mkdir -p "$lab"
cd "$lab"

cat > reconcile.sh <<'SCRIPT'
#!/usr/bin/env bash
set -Eeuo pipefail

readonly PROGRAM_NAME=${0##*/}

log() {
  local level=$1 message=$2
  shift 2
  printf 'time=%s level=%s component=%s message=%q' \
    "$(date --iso-8601=seconds)" "$level" "$PROGRAM_NAME" "$message" >&2
  printf ' %s' "$@" >&2
  printf '\n' >&2
}

retry() {
  local attempts=$1
  shift
  local n=1 status
  until "$@"; do
    status=$?
    (( n >= attempts )) && return "$status"
    log WARN 'retrying transient operation' "attempt=$n" "status=$status"
    sleep 0.1
    (( n += 1 ))
  done
}

flaky_probe() {
  local state_file=$1 count=0
  [[ -f $state_file ]] && count=$(<"$state_file")
  (( count += 1 ))
  printf '%d\n' "$count" > "$state_file"
  (( count >= 3 ))
}

ensure_line() {
  local file=$1 expected=$2 tmp
  [[ -e $file ]] || : > "$file"
  grep -Fxq -- "$expected" "$file" && return 0
  tmp=$(mktemp -- "${file}.tmp.XXXXXXXX")
  awk -v expected="$expected" '$0 != expected {print} END {print expected}' "$file" > "$tmp"
  mv -f -- "$tmp" "$file"
  log INFO 'configuration changed' "file=$file"
}

main() {
  local root=${1:?root directory required}
  mkdir -p "$root"
  retry 5 flaky_probe "$root/probe-count" || {
    log ERROR 'dependency did not recover'
    return 1
  }
  ensure_line "$root/service.conf" 'enabled=true'
  log INFO 'reconciliation complete'
}

main "$@"
SCRIPT

chmod u+x reconcile.sh
bash -n reconcile.sh
./reconcile.sh "$lab/state"
first_hash=$(sha256sum "$lab/state/service.conf")
./reconcile.sh "$lab/state"
second_hash=$(sha256sum "$lab/state/service.conf")
[[ $first_hash == "$second_hash" ]]
[[ $(grep -Fxc 'enabled=true' "$lab/state/service.conf") -eq 1 ]]
printf 'PASS: repeated run preserved converged state\n' 

6. Common automation mistakes

7. Knowledge check

8. Summary

Reliable automation is observable, bounded, selective, and convergent. Emit structured evidence, keep data and logs separate, place deadlines around external calls, retry only classified transient failures with capped backoff and jitter, and express operations as desired-state reconciliation. Then test repeated execution rather than merely asserting idempotency.

9. Further reading

• GNU Coreutils — timeout.
• GNU Bash Reference Manual — conditional expressions.
• flock(1) advisory locking.
• Service-specific API documentation for idempotency keys, rate limits, and retry semantics.