Profiling Shell Scripts with time and Timestamps

1. Performance work begins with measurement

A shell script can be slow because of CPU work, disk I/O, network latency, process creation, retries, or an external service. Measure before changing code.

flowchart LR
  T["total timing"] --> S["phase timings"]
  S --> H["hotspot"]
  H --> C["change"]
  C --> R["remeasure"]

2. Use Bash time for commands and compound commands

time grep -c 'ERROR' large.log

time {
  prepare
  build
  test
}

Bash's time reserved word can measure pipelines and grouped commands.

3. Interpret real, user, and sys time correctly

real is wall-clock elapsed time. user is CPU time in user space. sys is CPU time spent in kernel work. A network wait can produce high real time with very little CPU time.

4. TIMEFORMAT makes timing output consistent

TIMEFORMAT='elapsed=%3R user=%3U sys=%3S'
time run_build

Stable key-value timing fields are easier to compare across runs.

5. Use SECONDS for coarse phase timing

start=$SECONDS
build_project
elapsed=$((SECONDS - start))

printf 'phase=build duration_s=%d\n' "$elapsed" >&2

SECONDS is a Bash-native way to instrument long phases.

6. High-resolution timing can reduce portability

start_ns=$(date +%s%N)
run_operation
end_ns=$(date +%s%N)

printf 'elapsed_ns=%d\n' "$((end_ns - start_ns))"

7. One timing run is not a benchmark

Cache warmth, background load, network variability, filesystem state, and CPU scheduling can distort a single run. Repeat measurements and compare representative results.

8. Tracing helps explain behavior but changes timing

xtrace is excellent for finding duplicated commands or unexpected loops, but tracing adds overhead. Use traces to understand behavior and separate runs for measurement.

9. Record code version and workload with results

printf 'commit=%s dataset=%s\n' \
  "$(git rev-parse --short HEAD)" \
  "$dataset" >&2

TIMEFORMAT='elapsed=%3R user=%3U sys=%3S'
time ./process.sh "$dataset"

A benchmark without a code revision and workload description is difficult to reproduce.

10. Hands-on lab: phase-level timing

mkdir -p "$HOME/devops-academy/bash/chapter19/lesson03"
cd "$HOME/devops-academy/bash/chapter19/lesson03"

cat > profile-demo.sh <<'EOF'
#!/usr/bin/env bash
set -u

phase() {
  local name=$1
  shift

  local start=$SECONDS
  local status=0

  "$@" || status=$?

  local elapsed=$((SECONDS - start))
  printf 'phase=%s duration_s=%d status=%d\n' \
    "$name" "$elapsed" "$status" >&2

  return "$status"
}

phase prepare sleep 1
phase build sleep 2
phase test sleep 1
EOF

chmod u+x profile-demo.sh

TIMEFORMAT='total elapsed=%3R user=%3U sys=%3S'
time bash profile-demo.sh

11. Knowledge check

12. Summary

Measure total runtime, instrument meaningful phases, understand wall-clock versus CPU time, repeat benchmarks, and record the workload and code revision. Use deeper profilers when evidence points outside Bash.

13. Further reading

• GNU Bash Reference Manual — time and TIMEFORMAT.
• GNU time documentation where available.
• Linux perf and strace documentation for deeper profiling.
• Benchmarking methodology references.