Observability: metrics, alerts, logs / Stage 8 of 9

Investigating with logs

Not running Starting usually ~20 s

Step 5 of 6 · lab · 25 min

The site returns 500

From some moment on the hotel booking site answers its guests with error 500, and the nginx error.log is empty. Work out from the logs when the outage began and what caused it, write that down and bring the site back.

Situation

The hotel booking site is http://booking.lab.test/: nginx takes the requests and passes them to the lab-booking application. Guests write that the site answers "500 Internal Server Error". The on-call engineer has already opened the site's error.log — it is empty. The team lead asks for a short report: from what moment the site has been broken and which line in the logs explains it. And the site has to be brought back.

The site logs are /var/log/nginx/booking.access.log and /var/log/nginx/booking.error.log; the application writes to the systemd journal. Both are read with sudo.

Task

Write to ~/incident.txt: - as the first line — the time the outage began, to the second (from then on the site returns 500), in the form the journal or access.log uses: 2026-10-22 04:41:25 or 22/Oct/2026:04:41:25; - below it — the line from the application journal that shows the cause of the 500 answers.
http://booking.lab.test/ answers 200 again, and the page comes from the lab-booking application.
The site answers 200 after the application restarts too: sudo systemctl restart lab-booking.

Constraints

Do not change the application code /opt/booking/booking.py — look for the cause in its settings and fix it there.
The check itself restarts lab-booking and requests the site with a tag in the address: the answer must come from the application, not from nginx.

Visitors keep coming to the site while you investigate — new lines keep appearing in the logs.

Lab · on your own

No commands are given in this lab: type them in the terminal yourself. Goals are checked on the machine after every command.

Goals

0 of 4

http://booking.lab.test/ answers 200 — the page comes from the lab-booking application, its code is unchanged — not done yet
The first line of ~/incident.txt holds the time the outage began, to the second — from then on the site returns 500 — not done yet
~/incident.txt contains a line from the application journal that shows the cause of the 500 answers — not done yet
The site answers 200 after the application restarts too: sudo systemctl restart lab-booking — not done yet

Ctrl+Enter

Starts the machine node1 · Ubuntu 24.04

The machine is starting

Hints

0 of 3

Report a problem

Lab goals

0 of 4

http://booking.lab.test/ answers 200 — the page comes from the lab-booking application, its code is unchanged — not done yet
The first line of ~/incident.txt holds the time the outage began, to the second — from then on the site returns 500 — not done yet
~/incident.txt contains a line from the application journal that shows the cause of the 500 answers — not done yet
The site answers 200 after the application restarts too: sudo systemctl restart lab-booking — not done yet

node1 Ubuntu 24.04

Lab goals

0 of 4

http://booking.lab.test/ answers 200 — the page comes from the lab-booking application, its code is unchanged — not done yet
The first line of ~/incident.txt holds the time the outage began, to the second — from then on the site returns 500 — not done yet
~/incident.txt contains a line from the application journal that shows the cause of the 500 answers — not done yet
The site answers 200 after the application restarts too: sudo systemctl restart lab-booking — not done yet

Logs and audit · picked for this lab

journalctl — reading the systemd journal

Cheat sheet

$_ — insert into the terminal

journalctl -u nginx -f tail a service's logs
journalctl -xeu nginx investigate a failure
journalctl -p err -b errors from the current boot
journalctl -k kernel messages
journalctl _COMM=sshd -g fail by process, plus a text match
journalctl -b -1 the previous boot
journalctl --vacuum-time=7d clean up

Flag	Meaning
`-u <unit>`	only this service
`-f` / `-e`	follow / jump to the end
`-x`	add explanations to messages
`-p <prio>`	this priority or higher: emerg..debug (or err, warning)
`-b [N]`	the current (or Nth) boot
`-k`	kernel messages
`-g RE`	grep the text
`-o <fmt>`	output format: short, json, json-pretty, cat, verbose
`--since/--until`	a time range

Filtering by structured fields (without naming a service):

bash

journalctl _PID=1234              # by PID
journalctl _COMM=sshd             # by process name
journalctl _UID=1000 --since today
journalctl _SYSTEMD_UNIT=ssh.service -p warning
journalctl -o json-pretty -u nginx -n 1   # every field of one entry
journalctl --user -u myapp        # a user service

Commands

bash

journalctl -u nginx               # entries from the nginx service
journalctl -u nginx -f            # follow in real time (like tail -f)
journalctl -u nginx --since "10 min ago"
journalctl -xeu nginx             # tail with explanations
journalctl -p err -b              # only errors from the current boot
journalctl -k                     # kernel messages (like dmesg)
journalctl --since today --until "1 hour ago"
journalctl -b -1                  # the previous boot
journalctl -g 'pattern'           # grep messages (regex)
journalctl --disk-usage           # how much space it takes
sudo journalctl --vacuum-time=7d  # drop entries older than 7 days

By time: --since and --until

bash

journalctl -u nginx --since '10 min ago'
journalctl --since '-5min' -t lab-app
journalctl --since '2026-10-22 05:10' --until '2026-10-22 05:20'
journalctl --since today --until '1 hour ago'
journalctl --since yesterday -p err

The time is absolute ('2026-10-22 05:10', seconds are optional; a time without a date, '05:10', means today), Unix time after @ (@1792640000), or relative ('10 min ago', -5min, today, yesterday, now). The zone is the machine's time zone; --utc shows and reads time in UTC. The journal does not guess a wrong time: --since '25:00' gives Failed to parse timestamp: 25:00.

To match the journal against nginx and application logs, print the time with fractions of a second and the zone, like the ISO format of other logs:

text

$ journalctl -t lab-test -n 1 -o short-iso-precise
2026-10-22T05:18:46.155480+00:00 ubuntu lab-test[1536]:
  hello from forward

JSON: -o json and jq

-o json prints each entry as one JSON line with every field:

text

$ journalctl -t lab-test -n 1 -o json | jq -c '{__REALTIME_TIMESTAMP,
    _PID, PRIORITY, SYSLOG_IDENTIFIER, MESSAGE, _HOSTNAME}'
{"__REALTIME_TIMESTAMP":"1792646326155727","_PID":"1536","PRIORITY":"5",
  "SYSLOG_IDENTIFIER":"lab-test","MESSAGE":"hello from forward",
  "_HOSTNAME":"ubuntu"}

The output is wrapped here. All values are strings, numbers too: PRIORITY is "5". So in jq compare with a string: select(.PRIORITY == "3"); select(.PRIORITY == 3) finds nothing.

Field	What is in it
`__REALTIME_TIMESTAMP`	the entry time in Unix microseconds, UTC
`__MONOTONIC_TIMESTAMP`	microseconds since the machine booted
`MESSAGE`	the text
`PRIORITY`	severity as a number: 3 `err`, 4 `warning`, 5 `notice`, 6 `info`
`SYSLOG_IDENTIFIER`	the program tag, as with `-t`
`_SYSTEMD_UNIT`	the service that wrote the line
`_PID`, `_COMM`, `_HOSTNAME`	the process, its name, the machine
`_TRANSPORT`	where the entry came from: `journal`, `syslog`, `stdout`, `kernel`

SYSLOG_IDENTIFIER is the program name: for a Python service it is python3, not the service name; _SYSTEMD_UNIT names the service. Kernel entries (_TRANSPORT is kernel) have neither _SYSTEMD_UNIT nor _PID.

-o json-pretty is the same with indentation, for reading by eye. The entry time as a date with jq:

text

$ journalctl -t lab-test -n 1 -o json \
  | jq -r '.__REALTIME_TIMESTAMP | tonumber / 1000000 | floor | todate'
2026-10-22T05:18:46Z

Time and text in columns for sort and grep:

bash

journalctl --since '-5min' -t lab-app -o json \
  | jq -r '[.__REALTIME_TIMESTAMP, .MESSAGE] | @tsv'

Your own lines in the journal: logger and -t

text

student@ubuntu:~$ logger -t cleanup "removed 3 files"
student@ubuntu:~$ journalctl -t cleanup --no-pager -n 2
Oct 20 10:50:48 ubuntu cleanup[1143]: removed 3 files

logger -t tag writes a line to the journal under that tag, and journalctl -t tag shows only those lines. Output of a script run by a service is tagged with the script name: journalctl -t clean.sh. Outside the adm and systemd-journal groups, student sees only its own entries — read other users' and system entries with sudo.

The journal is empty after a reboot

journald isn't persistent. Create /var/log/journal (see "Overview"). journalctl -b -1 will then show the previous boot.

The journal is filling up the disk

journalctl --disk-usage, then --vacuum-time=7d or --vacuum-size=500M. A permanent cap goes in /etc/systemd/journald.conf (SystemMaxUse=500M).

You need logs for a specific failure

journalctl -xeu <unit> --since "5 min ago" is the most common diagnostic query (see systemctl).

The time in the journal looks "wrong"

journald stores entries in UTC internally and shows the local timezone. Check timedatectl; use journalctl --utc for UTC.

Failed to parse timestamp

--since or --until could not parse the time. The forms it reads are in journalctl: '2026-10-22 05:10', '10 min ago', -5min, today. Quote a time that has a space in it.

A service's logs show up in /var/log too (duplicates)

journald and rsyslog can both log the same thing. See rsyslog for text files vs journalctl for structured, per--u queries.

Investigating with logs

Situation

Task

Constraints

Signing in is needed to start the machine

Commands

By time: --since and --until

JSON: -o json and jq

Your own lines in the journal: logger and -t

The journal is empty after a reboot

The journal is filling up the disk

You need logs for a specific failure

The time in the journal looks "wrong"

Failed to parse timestamp

A service's logs show up in /var/log too (duplicates)