Linux Labs

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

Investigating with logs

Not running Starting usually ~20 s
Leave the lesson

Step 4 of 6 · on a machine · 9 min

The kernel on the same timeline

Sometimes the application has no time to write anything — then the kernel names the cause.

The kernel writes its own events to the journal — disks, network, memory; sudo journalctl -k shows them. For a service with a memory ceiling MemoryMax, a process that goes over the ceiling is ended by the kernel's OOM killer — with the line Memory cgroup out of memory: Killed process 1074 (python3). The process itself has no time to write anything, while systemd notes Failed with result 'oom-kill' in the service's journal and starts it again after RestartSec.

While the service restarts, nobody listens on its port, and nginx answers 502. In error.log it writes connect() failed (111: Connection refused) — the connection to the upstream was refused. On one timeline three sources add up to a story: in the second the 502s began in access.log, the kernel ended the process, and a couple of seconds later the service started and the answers were 200 again. journalctl without -u and -k shows the records of all sources mixed, in time order, — and --since with --until narrow it to the seconds you need.

Check yourself 1 question

With the 502 answers nginx wrote to error.log: connect() failed (111: Connection refused) while connecting to upstream. What does it mean?

  • The application never got the request: no connection was made. nginx passes the application's own answer as it is, like the 500 at the start of the lesson, and writes nothing to error.log.

  • The connection went to 127.0.0.1:8080 — inside the machine. A refusal means the port is closed: no process is listening on it.

  • nginx records a long wait as upstream timed out and answers 504. Here the connection was refused at once.

Connection refused means the connection was rejected: nobody was listening on 127.0.0.1:8080 because the process had ended and the new one had not started yet. That is the time to look for in the kernel's and the service's journals.

The kernel ends a service's processes every time it goes over the ceiling — even if nobody was using it at that moment. So a single Killed process line does not yet explain particular 502s: its time has to match the time of the answers in access.log. The seconds from access.log are easy to turn into a selection: --since and --until understand a time without a date — --since 04:53:27 --until 04:53:30 means "today, in these three seconds".

Exercise · do it

Find the process the kernel ended

Just now the site answered 502 for a few seconds and then recovered by itself. Find out from the logs which process the kernel ended in those seconds, and put its PID in ~/oom-pid.txt.

Sign in and start The machine is available after signing in

Goals · 0 of 1

  • Put the PID of the process from the 502 seconds in ~/oom-pid.txt not done yet

Step goals

0 of 1
  • Put the PID of the process from the 502 seconds in ~/oom-pid.txt — not done yet
Ubuntu 24.04

Step goals

0 of 1
  • Put the PID of the process from the 502 seconds in ~/oom-pid.txt — not done yet
Loading…