Memra

Logging a server

◈ 6 cards

Two logs with two readers: an audit log with one entry per request and an error log whose ideal length is zero; java.util.logging in practice; and a record in Common Log Format that Assignment 1 can parse.

Two logs, because they have two readers

Servers run unattended for months, and the only account of what happened is what they wrote down. But "log it" is not one decision, it is two, because there are two audiences.

The audit log gets one entry per request — who connected, what they asked for, what they got. It is read by programs: analysers that tally hits per host, bytes per client, requests per hour. It grows forever, and that is correct.

The error log gets unexpected exceptions only. It is read by you, line by line. A NullPointerException in a handler belongs here because it is a bug in your code. A client that disconnects mid-response does not — it is a normal event on the internet and it goes in the audit log, if anywhere. The ideal size of an error log is zero lines, and the rule that keeps it useful is unforgiving: every line is either a bug you fix or a log statement you delete. An error log full of false alarms is one nobody reads, which is the same as not having one.

The discipline

Two habits ruin more logs than any missing feature.

Debug logging in production. "Entering handleRequest", "loop iteration 5" — nobody ever reads these, they cost disk and they bury the three lines that mattered. Keep them in a separate file behind configuration, off by default.

Logging "just in case". You cannot guess in advance which message you will need at 3 a.m. six months from now; the evidence is that programmers are consistently bad at it. What you can do is make the audit record complete and structured, so the answer can be computed from it rather than hoped for.

java.util.logging in ten minutes

The JDK's own logging package is enough for this course and adds no dependencies.

  • One Logger per log, held in a private static final field: Logger.getLogger("requests"). Loggers are thread-safe, which they must be, because the file underneath is shared by every handler thread. Two loggers, requests and errors, give you the two logs above.
  • Seven levels, in descending seriousness: SEVERE, WARNING, INFO, CONFIG, FINE, FINER, FINEST. Use INFO for audit records and WARNING or SEVERE for the error log. Everything below CONFIG is debugging and does not ship.
  • Log the exception, not just its message: logger.log(Level.SEVERE, "handler failed", ex). The three-argument form keeps the stack trace, which is the only part you will actually use.
  • Configure from outside the code. -Djava.util.logging.config.file=logging.properties points at a properties file that chooses a FileHandler, its path, a size limit and a rotation count — so the destination changes without a recompile.

A record another program can parse

Assignment 2 has a requirement that is easy to miss and expensive to fix late: your server's log must be in the same format your Assignment 1 analyser reads. That is the common logfile format, one line per request, fields in a fixed order separated by single spaces:

127.0.0.1 - - [17/Jun/2026:22:53:58 -0600] "GET /index.html HTTP/1.1" 200 1043

Client host, two placeholders, a bracketed timestamp, the request line in double quotes, the status code, the byte count. Three rules make it machine-readable. Fixed field order, always — an optional field that sometimes disappears shifts every column after it. A literal - for a missing value, never an empty string, for exactly the same reason. And quotes around the request line, because it is the one field that contains spaces; the parser splits on spaces everywhere else and takes the quoted run as one token.

The timing rule follows from the content: the record names the status and the byte count, and neither is known until the response has been written. So you capture the client address at accept, the request line after parsing, the status and size after responding — and you write one record, at the end of the handler.

Worked example — both logs on the pooled server

public final class AccessLog {

    private static final Logger AUDIT = Logger.getLogger("requests");
    private static final Logger ERRORS = Logger.getLogger("errors");

    private static final DateTimeFormatter STAMP =
            DateTimeFormatter.ofPattern("dd/MMM/yyyy:HH:mm:ss Z", Locale.ENGLISH);

    public static void hit(Socket client, String requestLine, int status, long bytes) {
        AUDIT.info(String.format("%s - - [%s] \"%s\" %d %d",
                client.getInetAddress().getHostAddress(),
                STAMP.format(ZonedDateTime.now()),
                requestLine, status, bytes));
    }

    public static void bug(String where, Throwable ex) {
        ERRORS.log(Level.SEVERE, where, ex);
    }
}

The handler then calls AccessLog.hit(...) once, on its way out, and AccessLog.bug(...) only from a catch (RuntimeException ex) that wraps the whole request. Wrap the accept loop in the same way: a RuntimeException from one malformed request must not be allowed to end the server, and once it is caught it is unambiguously a bug — which is precisely what the error log is for.

The verification loop closes the module. Drive the server with a browser and with telnet, including a request for a file that does not exist, then run your Assignment 1 analyser over the log the server just produced. If every tally comes out, the two halves of the assignment agree. If it throws, you have found the format mismatch now rather than on submission day.

audit logerror logone entry perrequestunexpected exceptionclient errorsyes, hereneverideal sizegrows foreverzero lineslevelINFOWARNING or SEVEREread bya program (A1)you, every lineEvery error line is a bug to fix or a log call to delete.
The two logs differ in every dimension, which is why they are two files. The row that decides most cases is the second: a client that disconnects or sends garbage is a fact about the internet, not a bug in your code, so it is audit — never error.

source Harold 4e ch4 §Some Useful Programs; AU COMP 348 Assignment 2

hostGET /index.html200 and 1043accept()client address knownparse requestrequest line knownwrite responsestatus + bytes knownlog one recordall five fieldsOne record per request,written last.
Each stage of the handler contributes one field, and the last two — status and byte count — do not exist until the response has been written. Emitting the record earlier means guessing them, which is how a log ends up claiming 200 for a request that 404ed.

source Harold 4e ch9 §Logging; AU COMP 348 Assignment 2

NORMAL ~/memra/learn/comp-348/server-logging utf-8 LF