SRE practices: SLOs, incidents, redundancy / Stage 2 of 8 · step 5 of 6

Availability and p95 from the log

~30 min

Not running Starting usually ~20 s

Situation

The on-call engineers of the shop.lab.test store still compute its SLIs — availability and p95 response time — with a pipeline each of them types from memory, and the numbers for the same hour come out different for everyone. One script that everybody trusts is needed.

The site log is /var/log/nginx/shop.access.log (yesterday's is shop.access.log.1.gz); the line format is set in /etc/nginx/conf.d/sre-log.conf: each line ends with the response time $request_time and the request's unix time $msec. The nginx logs are read with sudo.

Task

Write the script ~/sli.sh that runs like this:

~/sli.sh LOG FROM TO

LOG is an nginx log in this format, plain or gzip-compressed (.gz);
FROM and TO are times in any form date -d understands: '2026-10-22 13:00', '2026-10-22T13:00:00';
the window takes the requests from FROM inclusive up to TO exclusive — by the request's unix time.

The script prints one line:

total=<requests in the window> availability=<availability> p95=<p95>

availability is the percentage of answers with a code below 500 among all requests of the window, two digits after the point (93.04);
p95 is the response time by the nearest rank: the times in ascending order, line number ⌈0.95 · total⌉, the value as written in the log;
for a window without requests — total=0 availability=- p95=-.

The check runs the script as you on its own logs that are not on the machine, so the script needs no sudo inside. You can check the script on the machine's log with ~/sli-check.txt: it holds a command and the line it must print.

The tools you need are already installed. There is no internet on the machine.

Lab goals

0 of 4

~/sli.sh is an executable script that prints one line total=… availability=… p95=… for the machine's log — not checked yet
On the check's logs total and availability match the reference — not checked yet
On the check's logs p95 matches the reference — not checked yet
The script reads a compressed log (.gz) itself and prints total=0 availability=- p95=- for a window without requests — not checked yet

Hints

0 of 3 open · they open one at a time

Hint 1

Show the solution after 3 failed checks

SRE · picked for this lab

SLI and SLO — the share of good requests and the error budget

Cheat sheet

$_ — insert into the terminal

combined + $request_time $msec: code $9, time $(NF-1), unix time $NF
lines from the last hour
awk -v f="$(date -d '1 hour ago' +%s)" '$NF >= f' access.log > w.log
availability SLI: share of responses without a 5xx
awk '$9 >= 500 {b++} END {printf "%.2f\n", 100*(NR-b)/NR}' w.log
p95 response time: nearest rank ⌈0.95 × N⌉
awk '{print $(NF-1)}' w.log | sort -n > /tmp/t
k=$(( ($(wc -l < /tmp/t) * 95 + 99) / 100 )); sed -n "${k}p" /tmp/t
error budget: SLO 99.5 % with 400000 requests in the window
awk 'BEGIN {print 400000 * (1 - 0.995)}' 2000 bad allowed
burn rate: 7 % errors at SLO 99.5 %
awk 'BEGIN {print 0.07 / (1 - 0.995)}' 14

Lines in a time window

A log with $msec at the end of the line:

bash

f=$(date -d '2026-10-22 10:00' +%s)
t=$(date -d '2026-10-22 11:00' +%s)
awk -v f="$f" -v t="$t" '$NF >= f && $NF < t' access.log > w.log
head -n 1 w.log; tail -n 1 w.log     # are the bounds inside?

Rotated parts are read together with the current file: zcat -f access.log.2.gz access.log.1 access.log | awk … (-f passes uncompressed files through as is). Give the window in the same time zone the log uses; on the lab machine that is UTC (+0000).

Without $msec, in plain combined, mktime turns the time into a number (on Ubuntu 24.04 awk is GNU awk):

bash

awk -v f="$f" -v t="$t" '
  { split($4, d, /[[\/:]/)
    m = (index("JanFebMarAprMayJunJulAugSepOctNovDec", d[3]) + 2) / 3
    s = mktime(d[4] " " m " " d[2] " " d[5] " " d[6] " " d[7])
    if (s >= f && s < t) print }' access.log > w.log

Availability from the log

bash

awk '$9 >= 500 {b++}
  END {printf "%d %d %.2f\n", NR, b, 100*(NR-b)/NR}' w.log

Prints the number of requests in the window, the number of 5xx responses and availability as a percentage with two decimals. In combined the status code is field 9. Check the field with awk '{print $9}' w.log | sort | uniq -c: it should list only codes.

p95 from $request_time

bash

awk '{print $(NF-1)}' w.log | sort -n > /tmp/t
n=$(wc -l < /tmp/t)
k=$(( (n * 95 + 99) / 100 ))      # ⌈0.95 × n⌉ in integers
sed -n "${k}p" /tmp/t

sort -n is required: without it 10.002 sorts before 2.001 (sort). An empty window gives n=0 and an empty answer. The share of fast responses uses the same field: awk '$(NF-1) <= 0.3 {f++} END {print f/NR}' w.log.

How much budget is left

bash

awk -v slo=0.995 -v total=400000 -v bad=1400 'BEGIN {
  ok = total * (1 - slo); left = ok - bad
  printf "allowed %d, left %d (%.0f%%)\n", ok, left, 100*left/ok }'

bad is the 5xx count for the window from the availability recipe, total is all requests in the window or their expected number.

High SLI, yet users complain

Requests never reached nginx: DNS, network, certificate. The log cannot see them — probe from outside, curl from another machine.
The application answers 200 with an error page. The SLI counts that as good: check the body or a dedicated health path.
Responses are slow: availability is fine, latency suffers. Add a latency SLI.
The outage fell outside the window: part of the lines is already in access.log.1 after the nightly rotation (logrotate).

p95 differs from another count

sorting without -n — string order instead of numeric order;
a different method: interpolation instead of nearest rank;
both window bounds included, so a line exactly at the end counted;
the time field is not a number: $upstream_response_time writes - for responses nginx served itself and 0.000, 0.002 with a comma when nginx retried the request on another server (nginx).

The window is empty

head -n 1 and tail -n 1 of the log show which period it covers. Common causes: the window is in a different time zone from the log; combined time compared as text while the month is a word ($4 breaks where months meet); the log is already rotated and the lines are in access.log.1 or .2.gz.

Field 9 is not the status

awk '{print $9}' | sort | uniq -c shows "GET, sizes or words — the request line has spaces or scanner garbage in it ("-", binary bytes). Taking the code by quotes is more robust: the first word after the request line.

bash

awk -F'"' '{split($3, f, " "); if (f[1] >= 500) b++}
  END {printf "%d %d\n", NR, b}' w.log

A 100 % SLO

A 100 % target leaves no budget. Any restart, release or network glitch breaks it, and the budget rule then forbids changes forever. A target higher than that of what the service depends on (network, hosting, database) cannot be met either.

Availability and p95 from the log

Situation

Task

Signing in is needed to start the machine

Lines in a time window

Availability from the log

p95 from $request_time

How much budget is left

High SLI, yet users complain

p95 differs from another count

The window is empty

Field 9 is not the status

A 100 % SLO