Tracking "file access denied" at the enterprise level

The request sounded like a reporting chore. A program needed to show, whenever an auditor asked, every instance in which a user had been denied access to a file. Produce the list; satisfy the control. It is not a reporting chore. The machines were already deployed, the standard was non-negotiable, and — as it turned out — the single line in the log that a person would point to as the answer is the wrong thing to build the report on. The right thing is a number that never appears in plain English at all.

The program was Future Combat Systems, at the time the largest contract SAIC had ever been awarded — on the order of fifteen billion dollars, as a subcontractor to Boeing. The relevant standard was the National Industrial Security Program Operating Manual, whose Chapter 8 governs information systems that touch classified work. Chapter 8 is broad; this is not an account of meeting all of it. It is an account of one finding — a failed attempt was made to access the file — and what it actually takes to produce that finding faithfully across a fleet.

The constraint that shaped everything

The machines had already been fielded. That single fact rules out the clean answer. You cannot re-image a running classified system, walk to each console, and hand-configure auditing; there are too many of them, they are in use, and touching them by hand does not scale or repeat. The auditing had to be retrofitted remotely, identically, and idempotently — the same operation applied to every host, safe to run twice, leaving proof behind.

So the work divided into three honest problems: reach every machine without a human at its keyboard; change what the kernel records without breaking the boot; and collect the records somewhere they become evidence rather than noise.

Reaching the machines without touching them

SSH is the obvious transport — a command prompt like telnet, but over an encrypted channel, run as a daemon, keying each host it meets. That last habit is the snag. The first time SSH contacts a host it wants to accept the host key interactively, and an interactive prompt is exactly what you cannot have in an unattended run across a fleet. The fix is to prime the known-hosts file ahead of time with ssh-keyscan, which fetches host keys non-interactively; keys can be pinned to names and to addresses independently. It was not strictly necessary to script this step, but building the keyring up front removes the one prompt that would otherwise stall the whole automation. (The small collector I used for this lived at iama.rrecktek.com/syslog/getkeys.pl.)

With the keyring primed, the logins themselves are automated with Expect driven from Perl. Expect exists to script interactive programs — it can even watch you drive a session by hand and write the script for you. The first thing my program did on each host was the least glamorous and the most important: confirm the machine was actually reachable on the network before assuming anything else. Then, over the automated SSH session, uname -a reported which kernel was running, which I matched against the four RedHat versions we supported — with a check to see whether a host had already been upgraded, so the run could be repeated without doing harm.

Changing the kernel without losing the boot

The auditing I needed lived below user space. In that era the practical way to record file-access outcomes at the system-call level on Linux was SNARE — audit and intrusion-detection software from InterSect Alliance, released under the GNU license, shipped as RPMs including an audit-enabled kernel (kernel-smp-2.4.21-15.EL.SNARE096) alongside snare-core and snare-gui, supporting RedHat ES 3 and 4, Fedora 2 and 3, and RedHat 9.0. Installing a new kernel on a machine you cannot walk over to is a thing you do carefully, and once.

RedHat keeps the bootloader and kernels on their own partition, /boot. Before replacing anything I backed that partition up wholesale — tar over /boot, then gzip — so a known-good boot was always one restore away. (dd would have served equally well.) Only then did the Expect payload copy the RPMs and configuration over and run the installs, grub.conf and the SNARE audit.conf going along with them. Back up first, change second: the ordering is the whole safety argument.

The audit.conf is where you say what “denied” means to the kernel. Every objective was written to fire on failure — open, creat, mkdir, mknod, link, symlink; chmod, rename, truncate, chown and its variants; the read-only and write/create/truncate/append forms of open; rmdir and unlink — each with return=Failure. That clause is the hinge of the entire exercise, and it deserves its own section, because it is where the surprise is.

The revelation: count the number, not the word

Here is the question that stopped me. Looking at the audit records SNARE produced, I could not find the finding. I asked Leigh Purdie, InterSect Alliance’s director, plainly: what part of this log line indicates that “a failed attempt was made to access the file”? I don’t see anything carrying that information.

His answer reframed the problem. An audit event, he explained, is composed of two parts written for two different readers. The objective bit is meant for a human — and to a human it helpfully includes the word failed when something goes wrong. It is an easy visual cue and a bad thing to key a report on. The event bit is meant for a machine, and it carries the truth in a form you can process: the system call’s return code. On a successful file open the return code is non-negative. On failure it is negative — and the negative number does not merely say something went wrong, it says what went wrong.

You decode it against the kernel’s own header. grep 13 /usr/include/asm/errno.h returns #define EACCES 13 /* Permission denied */. So return=-13 is not a string to be pattern-matched hopefully; it is a precise, machine-stated fact: permission denied. The audit trail was answering the question all along — just in the language of errno, not English.

This is the difference between a report you hope is right and one you can defend. Grepping for failed finds whatever happens to contain that word, in whatever phrasing the software chose, and misses whatever doesn’t. Counting return=-13 finds exactly the events the kernel itself classified as permission denied, and nothing else. When an auditor asks you to prove the control, you want to be counting the number.

Making the records line up, and turning them into evidence

Distributed logs are only trustworthy if their clocks agree, so each host got a time source — one line, server time.nist.gov, in /etc/ntp.conf — before anything was correlated across machines. Then the records were centralized. Stock syslog is clear text over UDP port 514; the collector runs syslogd -r to accept remote messages, and each client is pointed at it with a selector such as *.=info @loghost. SNARE writes its own copy through the same mechanism, an [Output] network=…:514 clause beside a local file=/var/log/audit.log. (The channel is unencrypted by default; when confidentiality of the log stream matters, the usual move is to tunnel syslog through stunnel, or run syslog-ng — but that is a separate hardening step, not part of the finding itself.)

Collection is not yet evidence. The last stretch was small Perl and one plotting tool. One program walked the aggregated log and split it into a tidy tree of day-level files — datadir/year/month/day/machine.log — so any day, on any host, is a single file you can hand over. A second program tallied occurrences of the event of interest per time bucket, keyed by hour and minute. And GNUplot turned the tally into a picture an auditor or a manager can read at a glance:

set terminal png large
set xlabel "Time"
set ylabel "Number of lines"
set title "Log Lines Per Minute"
set xtics rotate
set output 'occurences.png'
plot "linecount.data" with lines

A denial is now three things at once: a precise return=-13 record in a centralized store, a per-day file you can produce on request, and a curve over time that shows whether access-denied events are background noise or a spike worth investigating.

Why it matters

Two ideas outlast the particular tools, and both are older than the 2.4 kernel this ran on.

The first is that compliance is not a checkbox but an evidence-production capability. NISPOM Chapter 8 did not want a promise that access control existed; it wanted the ability to show denials, on demand, faithfully. Every architectural choice here — priming the keyring, backing up /boot before touching it, synchronizing clocks before correlating, centralizing before reporting — exists to make that production repeatable and trustworthy rather than heroic.

The second is the one Leigh Purdie handed me, and it generalizes far past this engagement: when a system speaks to both humans and machines, trust the channel built for machines. The human-readable word failed is a courtesy; the return code -13 is a contract, defined in a header file the kernel itself obeys. Build your detection on the contract. The prose is there to help you read; the number is there to be counted.

NISPOM Chapter 8 has since been superseded — classified-contractor information systems now fall under the Risk Management Framework and 32 CFR Part 117 — and the 2.4-era SNARE kernel belongs to its moment. But the mechanics haven’t really changed. Linux still records access outcomes as errno values, EACCES is still 13, and the discipline of counting the machine’s number instead of the human’s word is exactly as sound today, on auditd and journald, as it was on a fleet of already-deployed RedHat boxes with a compliance deadline overhead.

Notes and references

1. NISPOM, Chapter 8 — Information System Security, the control environment this work served (subsequently codified under 32 CFR Part 117, the NISPOM Rule).
2. InterSect Alliance — SNARE (System iNtrusion Analysis and Reporting Environment), the GPL audit software and audit-enabled kernel used here. My thanks to Leigh Purdie for the explanation at the center of this piece.
3. /usr/include/asm/errno.h — #define EACCES 13 /* Permission denied */. The definitive source for what a negative return code means.
4. ssh-keyscan(1), expect(1), and Perl’s Expect module — the automation transport.
5. syslogd(8) (-r), ntp.conf(5), and GNUplot — centralization, time, and the final graph.
6. Slides and code from the original talk, Meeting NISPOM Chapter 8 Compliance in the Linux Operating System: iama.rrecktek.com/syslog.