Bash and Linux

Wait for a Log Line

hardBash scripts and automation

Problem statement

Start an app in the background, wait until its log says ready, and give up with a clear error if that takes too long. Deploy scripts do exactly this before sending traffic to a new process, and getting it wrong either hangs the deploy forever or sends traffic too early.

The script starts a fake app that writes three lines to app.log, one at a time: starting, loading config, ready.

  1. Run 1: the app writes a line every 0.3 s, so it is ready after about 0.9 s. Wait up to 5 s.
  2. Run 2: the app writes a line every 2 s. Wait only 1 s and report the timeout.

Expected output:

TEXT
== run 1: app gets ready in about 0.9 s, wait up to 5 s ==
found 'ready': ok
log:
starting
loading config
ready
== run 2: app needs about 6 s, wait only 1 s ==
gave up: exit code 124 (124 means timeout)
log at that moment: 0 lines

Hints

Hint 1: tail -n +1 -F app.log prints the whole file and then every new line as it arrives. grep -q -m 1 ready exits as soon as it sees ready.

Approach

Optimal: tail -F, grep -m 1 and timeout

Covers: following a log with tail -F, grep -q -m 1, timeout and exit code 124, process substitution <(...) and $!, why tail -f | grep can hang, cleaning up the background processes.

Strict mode, used on every page in this section. The second line, set -euo pipefail, makes bash stop on mistakes instead of carrying on:

Option Means
-e exit as soon as a command fails (with some exceptions, see Handle Command Failures)
-u treat an unset variable as an error, instead of silently using empty text
-o pipefail a pipeline fails if any command in it fails, not just the last one

Put it right after the shebang line #!/usr/bin/env bash in every script you write.

The plan. Follow the log as it grows, stop the moment the right line appears, and never wait longer than a limit:

%%{init: {"flowchart": {"padding": 18, "nodeSpacing": 30, "rankSpacing": 40, "htmlLabels": true}, "themeVariables": {"fontSize": "18px"}}}%% flowchart TB T(["tail -n +1 -F app.log"]):::purple --> G(["timeout 5 grep -q -m 1 ready"]):::purple G --> OK["found: exit 0"]:::green G --> TO["time ran out: exit 124"]:::red classDef blue fill:#dbeafe,stroke:#2563eb,color:#1e3a8a,stroke-width:2px classDef yellow fill:#fef3c7,stroke:#d97706,color:#78350f,stroke-width:2px classDef green fill:#d1fae5,stroke:#059669,color:#064e3b,stroke-width:2px classDef red fill:#fee2e2,stroke:#dc2626,color:#7f1d1d,stroke-width:2px classDef purple fill:#ede9fe,stroke:#7c3aed,color:#4c1d95,stroke-width:2px classDef gray fill:#f3f4f6,stroke:#6b7280,color:#111827,stroke-width:2px linkStyle default stroke:#94a3b8,stroke-width:2px
Piece Does
tail -n +1 -F app.log print the file from line 1, then keep printing new lines; -F also survives the file being recreated or rotated
grep -q -m 1 ready exit with 0 as soon as one line matches; print nothing
timeout 5 ... stop the command after 5 seconds and exit with 124

The hidden trap: the pipe that never ends. The obvious version is tail -F app.log | grep -q -m 1 ready. When grep finds the line and exits, tail does not notice yet. It only dies when it next tries to write and finds the pipe closed. If the app logs nothing more, tail waits forever, and so does the pipeline, because bash waits for every command in it. Wrapped in timeout, it then reports a timeout even though ready was found.

%%{init: {"flowchart": {"padding": 18, "nodeSpacing": 30, "rankSpacing": 40, "htmlLabels": true}, "themeVariables": {"fontSize": "18px"}}}%% flowchart LR subgraph PIPE["tail -F | grep -m1"] direction TB P1["grep finds ready, exits"]:::green --> P2["tail still waiting
pipeline never ends"]:::red end subgraph SUB["grep < <(tail -F)"] direction TB S1["grep finds ready, exits"]:::green --> S2["done; kill tail"]:::green end PIPE ~~~ SUB classDef blue fill:#dbeafe,stroke:#2563eb,color:#1e3a8a,stroke-width:2px classDef yellow fill:#fef3c7,stroke:#d97706,color:#78350f,stroke-width:2px classDef green fill:#d1fae5,stroke:#059669,color:#064e3b,stroke-width:2px classDef red fill:#fee2e2,stroke:#dc2626,color:#7f1d1d,stroke-width:2px classDef purple fill:#ede9fe,stroke:#7c3aed,color:#4c1d95,stroke-width:2px classDef gray fill:#f3f4f6,stroke:#6b7280,color:#111827,stroke-width:2px linkStyle default stroke:#94a3b8,stroke-width:2px style PIPE fill:transparent,stroke:#dc2626,stroke-width:2px style SUB fill:transparent,stroke:#059669,stroke-width:2px

The fix: read from tail without waiting for it. exec 3< <(tail ...) starts tail in the background and connects its output to descriptor 3. $! holds tail's PID. Then timeout 5 grep -q -m 1 ready <&3 reads from it. When grep finds the line, it exits, and only grep's result decides the outcome. Afterwards, kill "$tailpid" stops tail and exec 3<&- closes the descriptor.

Walking through the code. The # Setup: lines only define the fake app, so skip past them.

  1. start_app 0.3 starts it in the background; wait_for_line ready 5 finds ready after about 0.9 s and returns 0. wait "$app" lets the app finish, then the log is printed.
  2. start_app 2 starts a slow app; wait_for_line ready 1 times out with 124 before even starting is written. The { ...; } 2>/dev/null hides bash's notice when the slow app is stopped.

|| rc=$? captures the timeout code without set -e stopping the script.

Edge cases. If the app crashes, it never logs ready, so the script waits the full timeout; also check that the process is still alive with kill -0. grep matches anywhere in a line, so not ready also matches ready; use -x or a stricter pattern. Some programs buffer their logs and write them in bursts, which can delay the line.

#!/usr/bin/env bash
set -euo pipefail

# Setup: a fake app that writes three lines to app.log, STEP seconds apart
cd "$(mktemp -d)"
start_app() {
  : > app.log
  { sleep "$1"; echo "starting" >> app.log
    sleep "$1"; echo "loading config" >> app.log
    sleep "$1"; echo "ready" >> app.log; } &
  app=$!
}

# wait_for_line PATTERN SECONDS: 0 when the line appears, 124 on timeout
wait_for_line() {
  local pattern=$1 seconds=$2 tailpid rc=0
  exec 3< <(tail -n +1 -F app.log 2>/dev/null)
  tailpid=$!
  timeout "$seconds" grep -q -m 1 -- "$pattern" <&3 || rc=$?
  kill "$tailpid" 2>/dev/null || true
  exec 3<&-
  return "$rc"
}

echo "== run 1: app gets ready in about 0.9 s, wait up to 5 s =="
start_app 0.3
if wait_for_line ready 5; then echo "found 'ready': ok"; fi
wait "$app"
echo "log:"; sed 's/^/  /' app.log

echo "== run 2: app needs about 6 s, wait only 1 s =="
start_app 2
if wait_for_line ready 1; then echo "found 'ready': ok"; else echo "gave up: exit code $? (124 means timeout)"; fi
{ kill "$app"; wait "$app"; } 2>/dev/null || true
echo "log at that moment: $(wc -l < app.log) lines"

Interview follow-ups

  • Wait for an HTTP health endpoint instead of a log line.

    Loop with curl and a deadline: deadline=$((SECONDS + 30)); until curl -fs --max-time 2 http://127.0.0.1:8080/health > /dev/null; do (( SECONDS < deadline )) || { echo "not ready after 30s" >&2; exit 1; }; sleep 1; done. -f makes curl fail on HTTP errors like 503, -s keeps it quiet, and --max-time stops one attempt from hanging. This is the same wait-with-a-limit idea, using the app's own answer as the signal.

Frequently asked questions

tail -f follows the file it opened. If the log is rotated (renamed and replaced with a new file), -f keeps reading the old renamed file and never sees new lines. tail -F follows the name: when the file is replaced or created later, it reopens it. For waiting on app logs, use -F, which also works when the log does not exist yet at the moment you start waiting.

When grep exits, tail only finds out the next time it writes to the closed pipe, and then gets SIGPIPE. If no more lines are written, that never happens, and bash waits for every command in a pipeline before moving on. The page avoids the pipeline: tail runs in a process substitution, so only grep is waited for, and tail is killed afterwards. Another common fix is grep -m 1 ... < <(tail -F file) in the same spirit.

It is a decent first step and very common, but a log line only says the app thinks it is ready. A stronger check asks the app itself, for example an HTTP health endpoint that returns 200 when it can really serve requests, as on the next page. Kubernetes uses this idea in readiness probes. Log-line waiting is still useful for tools that have no health endpoint, like a database finishing recovery.