Security Logging That Is Useful

Logging everything produces noise. Logging the right events produces an investigation you can actually complete.

Every incident review reaches the same question: what happened, exactly? The answer depends entirely on decisions made months earlier about what to record.

The events that matter

  • Authentication — success, failure, logout, MFA enrol, MFA failure, password change, reset requested and completed.
  • Authorization — every denial. A burst of 403s is one of the clearest attack signals you have.
  • Privileged actions — admin operations, impersonation, exports, bulk deletes, permission changes.
  • Credential lifecycle — tokens issued and revoked, API keys created and rotated, reuse detected.
  • Data access for sensitive records, where regulation or risk justifies it.
  • Configuration changes — feature flags, tenant settings, webhook endpoints.

What each entry needs

Who (actor, and the real actor when impersonating), what (event and target), when (with a timezone), where (IP, user agent), and a request id that ties everything together across services. Without correlation the log is a collection of unrelated lines.

Structured, always

JSON. A human-readable string is unqueryable at the moment you need to query it. "Show me every 403 for this user in the hour before the export" should be one query, not a grep.

Immutable and separate

An attacker with access to your application should not be able to edit the audit trail. Ship it somewhere append-only, with its own retention and its own access control.

And keep credentials out

Logs are copied into systems with weaker controls than your database. Identifiers, never values — a user id rather than an email, a truncated hash rather than a session id.

Example

Example · javascript
// One structured event, with everything an investigation needs
await audit.record({
  event: 'invoice.exported',
  actor: { id: user.id, type: 'user', impersonatedBy: session.impersonatedBy ?? null },
  target: { type: 'invoice_export', tenantId: user.tenant, rowCount: 4_213 },
  context: { ip: req.ip, userAgent: req.get('user-agent'), requestId: req.id },
  at: new Date().toISOString(),
});

// Note impersonatedBy: 'who did this?' must not answer 'the customer' when
// the real answer is 'a support agent, acting as the customer'.

When to use it

  • An investigation reconstructs an attacker's full path in minutes because every event shares a request id across services.
  • A burst of authorization denials from one account triggers an alert hours before any data is exfiltrated.
  • A regulator's question about who accessed a record is answered from an append-only audit store rather than from application logs.

More examples

An audit service worth building once

The unknown-event throw is the design decision that matters: a fixed vocabulary is what makes the log queryable a year later, during an incident.

Example · javascript
// A single, typed event vocabulary. Free-text event names become unqueryable.
export const AUDIT_EVENTS = {
  // authentication
  'auth.login.success': { severity: 'info' },
  'auth.login.failure': { severity: 'warn' },
  'auth.logout': { severity: 'info' },
  'auth.mfa.enabled': { severity: 'notice' },
  'auth.mfa.disabled': { severity: 'alert' },      // ← almost always interesting
  'auth.password.changed': { severity: 'notice' },
  'auth.password.reset_completed': { severity: 'notice' },
  'auth.token.reuse_detected': { severity: 'alert' },
  // authorization
  'authz.denied': { severity: 'warn' },
  'authz.role_changed': { severity: 'alert' },
  // privileged
  'admin.action': { severity: 'notice' },
  'admin.impersonation.started': { severity: 'alert' },
  'data.exported': { severity: 'notice' },
  'data.bulk_deleted': { severity: 'alert' },
  // configuration
  'config.webhook_changed': { severity: 'notice' },
  'config.api_key_created': { severity: 'notice' },
};

export const audit = {
  async record({ event, actor, target, context, metadata = {} }) {
    const spec = AUDIT_EVENTS[event];
    if (!spec) throw new Error(`Unknown audit event: ${event}`);   // keeps it typed

    const entry = {
      event,
      severity: spec.severity,
      at: new Date().toISOString(),

      // WHO — including the real actor behind an impersonation
      actorId: actor?.id ?? null,
      actorType: actor?.type ?? 'anonymous',
      impersonatedBy: actor?.impersonatedBy ?? null,
      tenantId: actor?.tenantId ?? null,

      // WHAT
      targetType: target?.type ?? null,
      targetId: target?.id ?? null,

      // WHERE and correlation
      ip: maskIp(context?.ip),
      userAgent: context?.userAgent?.slice(0, 200) ?? null,
      requestId: context?.requestId ?? null,
      sessionTag: context?.sessionId ? tag(context.sessionId) : null,

      // Extra, scrubbed of anything sensitive
      metadata: scrub(metadata),
    };

    // Two destinations: an append-only store for the record, and the log
    // stream for alerting.
    await Promise.all([
      auditStore.append(entry),
      logger[spec.severity === 'alert' ? 'error' : 'info'](entry, event),
    ]);

    if (spec.severity === 'alert') await alertSecurityChannel(entry);
    return entry;
  },
};

// Correlate across services: generate at the edge, propagate everywhere.
app.use((req, res, next) => {
  req.id = req.get('x-request-id') ?? randomUUID();
  res.set('X-Request-Id', req.id);
  asyncLocalStorage.run({ requestId: req.id }, next);
});

// Every outbound call carries it too, so a trace spans the whole estate.
fetch(url, { headers: { 'X-Request-Id': currentRequestId() } });

// Throwing on an unknown event name is what keeps the vocabulary usable —
// otherwise you end up with 'user_login', 'login', 'auth.login' and 'signin'.

Logging authorization denials, and using them

Recording not_owner separately from not_found while returning an identical 404 gives you the detection signal without reintroducing the existence oracle.

Example · javascript
// A single 403 is a client bug. Thirty in a minute from one account is a probe.
// This is the highest-signal, lowest-effort detection available.

export function auditDenial(req, res, reason, detail = {}) {
  audit.record({
    event: 'authz.denied',
    actor: { id: req.user?.id, type: req.user ? 'user' : 'anonymous',
             tenantId: req.user?.tenant },
    target: { type: detail.resourceType ?? 'unknown', id: detail.resourceId },
    context: { ip: req.ip, userAgent: req.get('user-agent'), requestId: req.id },
    metadata: { reason, method: req.method, path: req.route?.path ?? req.path },
  }).catch(() => {});      // never let auditing break the request
}

// Wire it into every rejection path
export function requireRole(role) {
  return (req, res, next) => {
    if (req.user?.role === role) return next();
    auditDenial(req, res, 'insufficient_role', { required: role });
    return res.status(403).json({ error: 'forbidden' });
  };
}

// Ownership failures matter MORE than role failures — they are the BOLA probe.
export async function findOwned(req, table, id) {
  const row = await db(table).where({ id, user_id: req.user.id }).first();
  if (!row) {
    // Distinguish "does not exist" from "exists, not theirs" INTERNALLY.
    // The response is 404 either way; the log records the difference.
    const exists = await db(table).where({ id }).first();
    auditDenial(req, null, exists ? 'not_owner' : 'not_found', {
      resourceType: table, resourceId: id,
    });
  }
  return row;
}

// ── The alerts that come out of it ───────────────────────────────────
// 1. Enumeration: many not_owner denials from one actor
//    count by actorId where reason='not_owner' over 5m > 20  → alert
//
// 2. Privilege probing: one actor hitting many distinct admin paths
//    distinct path count by actorId where reason='insufficient_role' > 5 → alert
//
// 3. Sequential ids: consecutive targetIds is close to a signature
//    (a legitimate client does not walk an id space)
//
// 4. A NEW denial reason appearing at volume
//    → usually a deploy broke a client, occasionally an attack

// The not_owner versus not_found distinction is the one that pays for itself:
// not_found is a broken client, not_owner is someone testing your boundaries.

Making the trail tamper-evident

The hash chain is cheap and gives you tamper-evidence rather than tamper-prevention — which is usually enough, because it turns a silent edit into an alert.

Example · javascript
// If an attacker with application access can edit the audit log, it proves
// nothing. Three levels, by cost.

// ── Level 1: append-only at the database ─────────────────────────────
// A separate table, a separate role, no UPDATE or DELETE grant.
//   CREATE TABLE audit_log (...);
//   GRANT INSERT, SELECT ON audit_log TO app_rw;
//   REVOKE UPDATE, DELETE ON audit_log FROM app_rw;
//
//   -- and a trigger, so even a privileged mistake is refused
//   CREATE RULE audit_no_update AS ON UPDATE TO audit_log DO INSTEAD NOTHING;
//   CREATE RULE audit_no_delete AS ON DELETE TO audit_log DO INSTEAD NOTHING;

// ── Level 2: a hash chain, so tampering is DETECTABLE ────────────────
import { createHash } from 'crypto';

export async function appendChained(entry) {
  const previous = await db('audit_log').orderBy('id', 'desc').first();

  const canonical = JSON.stringify(entry, Object.keys(entry).sort());
  const hash = createHash('sha256')
    .update((previous?.hash ?? 'genesis') + canonical)
    .digest('hex');

  return db('audit_log').insert({ ...entry, prev_hash: previous?.hash ?? null, hash });
}

// Verification: any edited or deleted row breaks the chain from that point on.
export async function verifyChain(from = 0) {
  const rows = await db('audit_log').where('id', '>', from).orderBy('id');
  let prev = from === 0 ? 'genesis'
    : (await db('audit_log').where({ id: from }).first())?.hash;

  for (const row of rows) {
    const { hash, prev_hash, id, ...entry } = row;
    const canonical = JSON.stringify(entry, Object.keys(entry).sort());
    const expected = createHash('sha256').update(prev + canonical).digest('hex');

    if (expected !== hash) {
      return { valid: false, brokenAt: id, expected, found: hash };
    }
    prev = hash;
  }
  return { valid: true, verified: rows.length };
}
// Run verifyChain nightly and alert on failure.

// ── Level 3: ship it somewhere the application cannot reach ──────────
// The strongest option: the audit stream is written to a destination the
// application has write-only access to and cannot read or modify.
//   - CloudWatch Logs with an immutable retention policy
//   - S3 with Object Lock in compliance mode
//   - a SIEM the application account cannot administer
//
// The property you want: compromising the API does not let you rewrite
// the record of the compromise.

Discussion

  • Be the first to comment on this lesson.