---
key: "security-logging"
title: "Create security logs someone can investigate"
url: "https://softwaresecurity.com/domains/runtime/detection/security-event-logging/"
api: "https://softwaresecurity.com/api/v1/articles/security-logging.json"
domain: "runtime"
topic: "Runtime, cloud \u0026 APIs"
type: "Guide"
identifiers: ["CWE-117","CWE-532","CWE-778","A09:2025","V16.2.1","V16.2.5","V16.3.2","V16.4.1","V16.4.3"]
tags: ["Injection","Error handling and information disclosure","Logging and detection","Incident response"]
stages: ["operate","respond"]
roles: ["developer","appsec-engineer","platform-sre"]
license: "CC-BY-4.0"
license_url: "https://creativecommons.org/licenses/by/4.0/"
code_license: "MIT"
---

# Create security logs someone can investigate

Record meaningful decisions with consistent structure, protect the resulting evidence, and prove that important events reach an operational owner.

Canonical URL: https://softwaresecurity.com/domains/runtime/detection/security-event-logging/

## In short

Log each security decision as one structured event with a fixed name, a UTC timestamp, actor, target, tenant, outcome, reason and an operation ID that survives retries, and log the committed effect separately from the request. Encode events as JSON so user input cannot forge entries, redact credentials by path and test with canary values, ship events to a separate store, and map the fields to a standard such as ECS or OCSF.

- A 200 response to `POST /roles` proves a response, not a role change; log the request, the decision and the committed effect, joined by an operation ID.
- Log injection (CWE-117) needs an unencoded delimiter: in JSON lines a newline stays inside the string value.
- Redaction covers only the paths you list: pino's `*.token` caught `credentials.token` but not a top-level `token`.
- Keep the time an event happened and the time it was ingested as separate fields, and deduplicate on a sequence or operation ID.
- OWASP Top 10:2025 names A09 Security Logging and Alerting Failures: events nobody alerts on do not count as detection.

## Recommended defaults

| Setting | Value | Note | Source |
| --- | --- | --- | --- |
| Format | One JSON object per line, with a fixed event name | — | OWASP ASVS 5.0 V16 Security Logging and Error Handling |
| Timestamps | UTC in ISO 8601, such as `2026-10-10T09:00:00.000Z`, from synchronized clocks | — | OWASP ASVS 5.0 V16 Security Logging and Error Handling |
| Credentials and session tokens | Never logged; hash or mask other sensitive values by data classification | — | OWASP ASVS 5.0 V16 Security Logging and Error Handling |
| Encoding of untrusted values | JSON string encoding by the logger; never concatenate input into a message | — | OWASP Logging |
| Storage | A logically separate system the application cannot modify | — | OWASP ASVS 5.0 V16 Security Logging and Error Handling |

## Verify it

1. Log a field containing `\n{"event":"forged"}` and confirm the output still has exactly one line for the event.
2. Send canary credentials in every redacted path and at other nesting depths, then search the log store for them; expect no match.
3. Make one allowed and one denied role change and confirm the accepted, committed and denied events carry the right operation IDs.
4. Stop the log shipper in a test environment and confirm that an alert fires and the outbox keeps undelivered events.
5. Confirm timestamps are UTC with an explicit offset and that the collector records its own ingestion time.

## What you will learn

- Reconstruct a security event from attempted and committed actions
- Design useful structured fields without logging credentials
- Recognize evidence gaps caused by clocks, sampling and failed delivery

Audience: Developers who add audit and security events to services, and the platform and security teams who collect and use them

Before you start:

- Trace a request from identity verification to its authorization decision and resulting effect.

Time: About 27 minutes: 7 to read and 20 for the exercise

## Start from an investigation question

Choose the decisions responders need to reconstruct: who changed a role, why an authorization check failed, which session was revoked, or whether an export completed. Infrastructure access logs rarely explain all of these application decisions. Assign each event a clear meaning before adding more fields.

Use a consistent event vocabulary across services. Record an event type, timestamp, service/version, actor reference where appropriate, operation, target reference, outcome, reason category, and correlation identifier. Distinguish an attempted action from its successful completion so a request log is not mistaken for proof of a business effect.

Logs your customers cannot get do not help them. In the 2023 Storm-0558 intrusion, the only victim to detect it did so with a mailbox access log that required a premium licence, and other victims could not see past activity at all: /domains/identity-crypto/authentication/case-study-storm-0558/.

## Worked investigation: did a permission change actually take effect?

An incident responder asks whether a support operator changed a customer’s role. An access log contains `POST /roles` with status 200. That line establishes an HTTP response, not the resulting authorization state: the handler may return before a worker commits, or the response may describe an accepted request. Define separate events for the request, policy decision and committed effect, and connect them with an operation identifier.

Use a stable actor reference from verified identity, a target reference, tenant, action, outcome and reason category. Add service revision and policy version so the responder can reconstruct which rule ran. In the example, operation op-41 was denied by tenant-policy-v8; op-42 was allowed and later committed. `request_id` changes on retries, while `operation_id` identifies one logical action. Neither identifier should be a bearer token or raw session cookie.

The record below intentionally avoids free-form request bodies. A malicious display name containing a newline remains data inside a JSON string rather than a forged second log entry; the fix card at /fix/crlf-log-injection/ covers plain-text logs. Even a structured logger needs bounded fields and safe downstream rendering: a spreadsheet export can interpret formula prefixes, and a web console can render HTML unsafely. The logging transport should preserve event boundaries and authenticity, not simply concatenate user input with text.

A durable audit event can be coordinated with a business transaction through an outbox: commit the role change and its pending audit record together, then deliver the audit record asynchronously with deduplication. This closes a particular gap between committed changes and lost logs. It does not prove the collector is immutable or that the actor was legitimate. Decide which operations must refuse to proceed when their required evidence cannot be persisted, rather than making every logging outage either fail-open or a site-wide denial of service.

```json
{"event":"role_change.denied","operation_id":"op-41","actor":"support-7","tenant":"north","target":"south:user-9","reason":"tenant_boundary","policy":"tenant-policy-v8","service_revision":"r52"}
{"event":"role_change.accepted","operation_id":"op-42","actor":"support-7","tenant":"north","target":"north:user-3"}
{"event":"role_change.committed","operation_id":"op-42","actor":"support-7","tenant":"north","target":"north:user-3","old_role":"reader","new_role":"editor","audit_sequence":918}

```

## Emit the events with a structured logger

The module below configures pino 10 for security events: one JSON object per line, UTC timestamps, service fields on every event, a fixed message per event name and redaction of the `Authorization` header, cookies, passwords and tokens. Logging the denied and committed role changes from the example produced exactly two lines, even though the display name contained a newline followed by a forged `role_change.committed` event: the newline was written as `\n` inside the JSON string. The bearer token and the nested token were replaced by `[REDACTED]`.

Redaction is path-based. In the same test `*.token` matched `credentials.token` but not a top-level `token` or `session.auth.token`, both of which were logged in clear text. List every path, keep secrets out of event objects in the first place, and test with canary values at several depths.

```javascript
// Structured security events with pino 10: JSON lines, UTC timestamps and redaction of credentials.
import pino from 'pino';

export const audit = pino({
  base: {service: 'accounts', service_version: 'r52'},
  timestamp: pino.stdTimeFunctions.isoTime, // "time":"2026-10-10T09:00:00.000Z"
  redact: {
    paths: ['req.headers.authorization', 'req.headers.cookie', '*.password', '*.token'],
    censor: '[REDACTED]',
  },
});

// One event per decision; the message is a fixed event name, never user input.
export function roleChange(stage, fields) {
  audit.info({event: `role_change.${stage}`, ...fields}, `role_change.${stage}`);
}
```

## Keep the event useful and bounded



- Exclude passwords, bearer tokens, raw session identifiers, unnecessary personal data, and full sensitive request or response bodies.
- Use structured logging and safely encode untrusted field values. Bound field lengths and prevent line breaks or delimiters from forging additional events.
- Protect transport and storage, restrict access, monitor changes to collection, and define retention and disposal for the actual investigation need.
- Maintain time synchronization and record collection delays. Do not silently sample away events essential to an audit or incident sequence.
- Choose severity from context. A single rejected request is not automatically a critical incident; repeated or consequential patterns may deserve escalation.

## Map the fields to ECS or OCSF

A common schema lets the SIEM correlate your security events with audit logs from other systems and the rest of your observability data. The Elastic Common Schema is being merged into the OpenTelemetry semantic conventions; OCSF is used by Amazon Security Lake and other security data platforms. The table maps the vocabulary of the worked example; in OCSF 1.9 a role change belongs to the User Management class, with activity 16, Assign Roles; the older User Access Management class is deprecated.

| Field in the example | ECS | OCSF 1.9 (User Management, 3007) |
| --- | --- | --- |
| `event` (`role_change.committed`) | `event.action`, with `event.category: iam` and `event.type: change` | `class_uid` 3007 and `activity_id` 16 |
| Time the action happened | `@timestamp` | `time` |
| Time the collector received it | `event.ingested` | `metadata.logged_time` |
| `actor` | `user.id` | `actor.user.uid` |
| `target` | `user.target.id` | `user.uid` |
| `tenant` | `organization.id` | `metadata.tenant_uid` |
| Outcome (allowed, denied) | `event.outcome`: success or failure | `status_id`: 1 Success or 2 Failure |
| `reason` | `event.reason` | `status_detail` |
| `operation_id` | `trace.id`, or a custom field | `metadata.correlation_uid` |
| `service_revision` | `service.version` | `metadata.product.version` |

## Test the path to a human decision

Generate synthetic authentication, authorization, administrative-change, and revocation events in a test environment. Verify that each arrives with the correct meaning and can be correlated without exposing a secret. Include malicious-looking names, very long values, and unavailable log storage.

Confirm that logging failures have a deliberate service behavior and raise an operational signal without recursively flooding logs. Exercise one alert through acknowledgment and investigation, as the runtime detection and response guide at /domains/runtime/detection/runtime-detection-response/ describes. Preserve event definitions, example records, retention settings, and owners. A dashboard of collected bytes demonstrates ingestion; a responder answering the original investigation question demonstrates usefulness.

## Diagnose incomplete fixes

Ordering solely by collector timestamps can reverse a real sequence when events are delayed or clocks disagree. Preserve event time and ingestion time, use operation IDs and supported sequence/transaction identifiers, and record clock uncertainty where it affects conclusions. Do not invent a precise order from timestamps with overlapping uncertainty.

High log volume is not the same as good detection. A denied request may be routine; a rare allowed privilege change may deserve stronger attention. Define which events must not be sampled, then test that a responder can answer one concrete question using retained records. Review who can delete, modify or disable collection and alert on changes to that path.

## Check the result against concrete cases

These outcomes belong to the worked example; the logger test above covers the encoding and redaction rows, and the delivery rows need a test of your own collector.

| Case | Expected result | What it establishes |
| --- | --- | --- |
| op-41 has only a denied event | No role-change success established | Decision outcome is explicit |
| op-42 accepted and committed | Commit established for target north:user-3 | Business effect differs from request |
| Collector receives same sequence twice | One logical audit event after deduplication | At-least-once delivery handled |
| Missing sequence 919 | Investigate an evidence gap | Silence is not a benign outcome |
| Raw `Authorization` field appears | Fail log-sanitization check | Secrets are not evidence fields |

## Guided practice

Use a short event timeline to determine which account changed, which action was denied, and what cannot be concluded.

### Supplied material

```text
10:00:00 app: op-41 role_change.denied, target south:user-9, reason tenant_boundary.
10:00:01 app: op-42 role_change.accepted, target north:user-3.
10:00:03 app: op-42 role_change.committed, reader→editor, sequence 918.
10:00:02 collector time: receives sequence 918.
10:00:05 collector time: receives duplicate sequence 918.
Last known outbox sequence is 919; collector has no 919.
Proposed debug field: Authorization=Bearer SECRET-DEMO.
Clock note: app may be two seconds ahead of collector.
```

### 1. Separate attempt from effect

Identify the operation that changed a role and the operation that did not establish a change.

Worked answer: op-42 has explicit commit evidence for north:user-3, changing reader to editor. op-41 records denial for south:user-9; the fixture contains no commit for that attempt. Merely seeing the denied target in a log is not evidence it was modified.

### 2. Deduplicate and order cautiously

Count committed changes represented by the two collector deliveries and interpret the timestamp inversion.

Worked answer: Both deliveries have sequence 918 and operation op-42, so they represent one recorded commit. Collector 10:00:02 preceding app 10:00:03 is compatible with the stated clock skew; it does not demonstrate time travel or tampering.

### 3. Identify the unanswered question

Explain what missing sequence 919 means and what to inspect next.

Worked answer: There is a delivery or retention gap. Inspect the durable outbox, relay retry state, collector acknowledgment and retention controls. The fixture does not reveal what 919 contains, so neither a second role change nor absence of one can be asserted.

### 4. Replace unsafe debugging

Remove the proposed bearer field and name evidence that retains investigative usefulness.

Worked answer: Keep actor reference, authentication method/result category, operation ID, policy revision and redacted credential identifier if the design supports one. Do not retain the bearer value. If it has already been logged, treat its retained copies and credential validity as a separate exposure to remediate.

Deliverable: A record that separates the denied attempt from the committed change, counts one commit despite duplicates, explains the missing sequence and replaces the unsafe debug field.

Scope: The timeline is supplied; the logger module and verification steps on this page show how to produce and test the same events in a service.

Articles and teaching material: CC BY 4.0. Original executable code: MIT. Attribution: Software Security.

## Sources

- [OWASP Logging](https://cheatsheetseries.owasp.org/cheatsheets/Logging_Cheat_Sheet.html)
- [OWASP Logging Vocabulary](https://cheatsheetseries.owasp.org/cheatsheets/Logging_Vocabulary_Cheat_Sheet.html)
- [OWASP ASVS 5.0 V16 Security Logging and Error Handling](https://github.com/OWASP/ASVS/blob/v5.0.0_release/5.0/en/0x25-V16-Security-Logging-and-Error-Handling.md). Version 5.0.0.
- [OWASP Top 10:2025 A09 Security Logging and Alerting Failures](https://top10.owasp.org/2025/A09_2025-Security_Logging_and_Alerting_Failures/)
- [CWE-117: improper output neutralization for logs](https://cwe.mitre.org/data/definitions/117.html). CWE version 4.20.
- [pino: redaction](https://github.com/pinojs/pino/blob/main/docs/redaction.md)
- [Elastic Common Schema: event fields](https://www.elastic.co/docs/reference/ecs/ecs-event)
- [OCSF schema 1.9.0: User Management](https://schema.ocsf.io/1.9.0/classes/user_management)