Chapter 17 — Critical infrastructure and sector security: tooling
Lesson map
Lesson 17 published. Map, example, EX049.
flowchart TD
N0["Learning outcomes and connection"]
N1["17.1 What to log"]
N2["17.2 Time"]
N3["17.3 Structured logs and syslog"]
N4["17.4 Normalization"]
N5["17.5 Tools you can trust"]
N6["17.7 Practical activity: normalizer"]
N7["Chapter synthesis"]
N0 --> N1 --> N2 --> N3 --> N4 --> N5 --> N6 --> N7
N7 --> EX["Worked example"]
EX --> Q["Exercise EX049"]
Logical drawing
flowchart LR
N0["Learning outcomes and connection"]
N1["17.1 What to log"]
N2["17.2 Time"]
N3["17.3 Structured logs and syslog"]
N4["17.4 Normalization"]
N5["17.5 Tools you can trust"]
N6["17.7 Practical activity: normalizer"]
N7["Chapter synthesis"]
N0 --> N1 --> N2 --> N3 --> N4 --> N5 --> N6 --> N7 --> Q["EX049"]
[Learning outcomes and connection]
|
v
[17.1 What to log]
|
v
[17.2 Time]
|
v
[17.3 Structured logs and syslog]
|
v
[17.4 Normalization]
|
v
[17.5 Tools you can trust]
|
v
[17.7 Practical activity: normalizer]
|
v
[Chapter synthesis]
|
v
[Worked example] --> [Exercise EX049]
Learning outcomes and connection
After this chapter you should be able to:
- configure systems to produce logs that answer operational and security questions;
- keep clocks synchronized and record time in a single, unambiguous format;
- normalize logs from different sources into a common structure;
- write and test a small tool so that you can trust its output, and know when to use an existing one instead.
Monitoring (Chapter 19), troubleshooting (Chapter 20) and evaluation (Chapter 23) all depend on logs. Most logging failures are not missing products but missing basics: a source that never forwarded, a timestamp with no time zone, a parser that silently drops lines it does not understand.
17.1 What to log
Log what you will need to answer the questions you will be asked: who logged in, from where, with what result; what configuration changed; what the relay accepted, rejected and quarantined, with counts; what flows crossed zone boundaries; when services started, stopped or failed. NIST's log-management guide covers planning, generation, transmission, storage and analysis of logs (NIST SP 800-92). Forward logs off the host promptly — a compromised or failed host cannot be trusted to keep its own records — and monitor that forwarding continues.
17.2 Time
Ordering events across systems requires agreed time. Synchronize every host with a trusted time source using NTP (RFC 5905); in LANTERN the relays take time from two internal servers and serve it to stations. Record timestamps in a format with explicit offset, such as those defined in RFC 3339, and convert to UTC for analysis. Monitor clock offset itself: a host whose time source has failed drifts slowly and silently.
17.3 Structured logs and syslog
The syslog protocol, RFC 5424, defines a message with priority (facility and severity), version, timestamp, hostname, application name, process ID, message ID, structured data (key–value parameters in brackets) and free-text message. Structured data are what make logs searchable: src="192.0.2.44" user="root" can be counted and filtered; the same information buried in prose must be guessed at with patterns. Older devices often send the earlier BSD format, without year or time zone; record such sources as lower-quality and convert carefully.
17.4 Normalization
A normalizer turns each source's format into one common record: UTC time, host, application, severity, and named fields such as src, user, dst, dport, action. Downstream rules (Chapter 19) are then written once. A normalizer must count what it cannot parse and report it: silent drops are how a monitoring system goes blind to the one source that changed its format.
The relay's BSD-format line in the worked night shows why: without an unparsed count, it would simply have vanished.
The kiosk line with no timestamp at all is the other case: the normalizer must flag it, not stamp it with arrival time.
17.5 Tools you can trust
Implementers write small tools constantly. Trust in a tool's output comes from: a clear statement of what it handles and what it does not; tests with bad and edge cases (Chapter 3); counts of inputs, outputs and rejects that add up; deterministic output for the same input; and version control. Write your own tool when the task is small and specific; use an established, maintained tool when the task is general (a full syslog collector, a TLS library, a database). Never write your own cryptography — use the standard library's.
17.6 Worked example: a night's logs (synthetic)
Lab 17 parses seven lines from the relay, firewall, historian and depot kiosk. Six parse, one does not: a BSD-format line from the relay's own application, revealing that one LANTERN component was never configured for the agreed format. One line has no timestamp at all (the kiosk). The historian's line carries +01:00; converted to UTC it is 22:02:11 — before the SSH events, not after as its local time suggests. Sorted in UTC, the night reads: historian disk-quota error at 22:02, a legitimate administrator login at 22:14, two failed root logins from an external address at 22:15, and a corporate-to-PS-04 Modbus flow at 22:16 from the same workstation used for the administrator login.
17.7 Practical activity: normalizer
Lab 17 (save as lab17.py, run with python3 lab17.py):
# Lab 17 - normalizing RFC 5424-style syslog lines into JSON records (offline, standard library only)
# Synthetic log lines from the relay, historian and firewall. Simplified parser for teaching, not a full RFC 5424 implementation.
import json, re
from datetime import datetime, timezone
LINE = re.compile(r"<(?P<pri>\d{1,3})>1 (?P<ts>\S+) (?P<host>\S+) (?P<app>\S+) (?P<proc>\S+) (?P<msgid>\S+) (?P<sd>-|\[.*?\]) ?(?P<msg>.*)")
SEV = ["emerg", "alert", "crit", "err", "warning", "notice", "info", "debug"]
lines = [
'<86>1 2026-10-11T22:14:03.120Z rly-01 sshd 812 AUTH [meta src="10.40.3.7" user="b.lind"] Accepted publickey',
'<84>1 2026-10-11T22:15:40.004Z rly-01 sshd 813 AUTH [meta src="192.0.2.44" user="root"] Failed password',
'<84>1 2026-10-11T22:15:41.917Z rly-01 sshd 813 AUTH [meta src="192.0.2.44" user="root"] Failed password',
'<134>1 2026-10-11T22:16:00.000Z fw-hub filter - FLOW [flow src="10.40.3.7" dst="10.20.0.11" dport="502" act="allow"]',
'<131>1 2026-10-11T23:02:11+01:00 hist-01 histsvc 4410 DBERR - write failed: disk quota',
'Oct 11 22:17:00 rly-01 relay: legacy BSD-format line',
'<13>1 - kiosk-depot app - - - no timestamp supplied',
]
SDPARAM = re.compile(r'(\w+)="((?:[^"\\]|\\.)*)"')
out, bad = [], 0
for raw in lines:
m = LINE.fullmatch(raw)
if not m:
bad += 1; print("UNPARSED:", raw[:40]); continue
pri = int(m["pri"])
rec = {"ts": None if m["ts"] == "-" else m["ts"], "host": m["host"], "app": m["app"],
"facility": pri // 8, "severity": SEV[pri % 8], "msgid": m["msgid"], "msg": m["msg"]}
rec.update(dict(SDPARAM.findall(m["sd"])))
if rec["ts"]: # normalize every timestamp to UTC so sources can be ordered together
rec["ts_utc"] = datetime.fromisoformat(rec["ts"]).astimezone(timezone.utc).strftime("%Y-%m-%dT%H:%M:%S.%f")[:-3] + "Z"
out.append(rec)
for r in sorted(out, key=lambda r: r.get("ts_utc") or ""):
print(r.get("ts_utc"), r["host"], r["severity"], r.get("src", "-"), r["msg"] or r["msgid"])
print(json.dumps(out[1], sort_keys=True))
print(f"parsed {len(out)}, unparsed {bad}, missing timestamp {sum(r['ts'] is None for r in out)}")
Expected output (Python 3.13.5):
UNPARSED: Oct 11 22:17:00 rly-01 relay: legacy BSD
None kiosk-depot notice - no timestamp supplied
2026-10-11T22:02:11.000Z hist-01 err - write failed: disk quota
2026-10-11T22:14:03.120Z rly-01 info 10.40.3.7 Accepted publickey
2026-10-11T22:15:40.004Z rly-01 warning 192.0.2.44 Failed password
2026-10-11T22:15:41.917Z rly-01 warning 192.0.2.44 Failed password
2026-10-11T22:16:00.000Z fw-hub info 10.40.3.7 FLOW
{"app": "sshd", "facility": 10, "host": "rly-01", "msg": "Failed password", "msgid": "AUTH", "severity": "warning", "src": "192.0.2.44", "ts": "2026-10-11T22:15:40.004Z", "ts_utc": "2026-10-11T22:15:40.004Z", "user": "root"}
parsed 6, unparsed 1, missing timestamp 1
Check two things in the output. First, the unparsed count is 1, the relay application's BSD-format line, which is a configuration fault in a LANTERN component, not noise. Second, the historian's +01:00 line, converted to UTC, sits at 22:02:11, before the 22:14 administrator login and the 22:15 failed root logins rather than after them. Sorted that way, the corporate-to-PS-04 Modbus flow at 22:16 follows an administrator login from the same workstation, which is the sequence Rule B will later flag.
17.8 Common errors and limits
- Logging everything at debug level, filling disks (Chapter 1) and hiding the events that matter.
- Logs kept only on the host that produced them.
- Timestamps without time zone; mixing local time and UTC in one analysis.
- Parsers that drop unparseable lines without counting them.
- Assuming log forwarding still works because it worked last month.
- Building a home-made tool where a maintained one exists, or home-made cryptography ever.
The lab's parser is a teaching simplification of RFC 5424: it does not handle every escape sequence or multiple structured-data elements. It reports what it cannot parse, which is the property that matters most.
Exercises — chapter 17
EX049 — Fix the relay's format. Objective: handle a non-conforming source. Inputs: Lab 17's unparsed line. Constraints: two options. Steps: (1) describe fixing the source (configuration change on the relay); (2) describe adding a second parser for BSD format; (3) say which you would do first and why, and what the BSD parser cannot recover. Expected evidence: half page. Rubric: 3 = fix at source first (it is our own component, under change control), BSD parser as a fallback for third-party devices; BSD lines lack year and zone so the parser must assume them and mark records as lower-quality; 2 = one option; 1 = "ignore it"; 0 = none.
EX050 — Order of events. Objective: see the effect of time zones. Inputs: Lab 17 output. Constraints: none. Steps: (1) list the events in order of their written timestamps, ignoring offsets; (2) list them in UTC order; (3) explain how an investigator using the first order would misread the historian event. Expected evidence: two lists and explanation. Rubric: 3 = historian event appears last in written order (23:02) but first in UTC (22:02); investigator might wrongly link the disk-quota error to the failed logins; 2 = lists right, explanation thin; 1 = one list; 0 = none.
EX051 — Count what you drop. Objective: add a self-check to the tool. Inputs: Lab 17. Constraints: standard library only. Steps: (1) add a check that the number of input lines equals parsed plus unparsed and exits with an error otherwise; (2) add a per-host count of unparsed lines; (3) explain why a monitoring system should alert when a host's unparsed count rises. Expected evidence: code, output, explanation. Rubric: 3 = invariant enforced, per-host counts printed (rly-01: 1), explanation that a format change on one source silently blinds rules; 2 = partial; 1 = not run; 0 = none.
Chapter synthesis
Log what you will need to answer, forward it off the host, and check that forwarding continues. Synchronize clocks, record time with explicit offsets and analyse in UTC. Normalize sources into one structure, count everything you cannot parse, and build small tools with tests and invariants so that their output can be trusted; use established tools for general jobs and never invent cryptography.
Continue studying — chapter 17 of 30
← Chapter 16 · Course chapter index · Chapter 18 →
Continue to the next authored lesson.