Log Analysis and Diagnostic Data Gathering Questions

Direct answer

Detect which of the three formats a given timestamp string is in with a small set of targeted checks (a fixed-width digit string is epoch seconds; a specific pattern is Apache's format; anything else is attempted as ISO 8601), parse it into a timezone-aware value, convert to UTC, and format as an ISO 8601 string. Anything that doesn't match any of the three raises a clear, typed error rather than silently returning a wrong time.

Approach

import re
from datetime import datetime, timezone


class TimestampParseError(ValueError):
    pass


_EPOCH_RE = re.compile(r'^\d{9,10}$')
_APACHE_RE = re.compile(r'^\d{2}/[A-Za-z]{3}/\d{4}:\d{2}:\d{2}:\d{2} [+-]\d{4}$')


def normalize_timestamp(raw):
    """Parse a timestamp in Apache clf, ISO8601, or epoch-seconds form and
    return a UTC ISO8601 string. Raises TimestampParseError on anything
    else, rather than silently returning a wrong time.
    """
    raw = raw.strip()

    if _EPOCH_RE.match(raw):
        dt = datetime.fromtimestamp(int(raw), tz=timezone.utc)
        return dt.strftime("%Y-%m-%dT%H:%M:%SZ")

    if _APACHE_RE.match(raw):
        dt = datetime.strptime(raw, "%d/%b/%Y:%H:%M:%S %z")
        return dt.astimezone(timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ")

    try:
        iso_raw = raw[:-1] + "+00:00" if raw.endswith("Z") else raw
        dt = datetime.fromisoformat(iso_raw)
        if dt.tzinfo is None:
            raise TimestampParseError(f"timestamp has no timezone info: {raw!r}")
        return dt.astimezone(timezone.utc).strftime("%Y-%m-%dT%H:%M:%SZ")
    except ValueError:
        pass

    raise TimestampParseError(f"unrecognized timestamp format: {raw!r}")


samples = [
    "10/Oct/2024:13:55:36 -0700",
    "2024-10-09T11:23:45Z",
    "1700000000",
    "not-a-timestamp",
]

for s in samples:
    try:
        print(f"{s!r:40} -> {normalize_timestamp(s)}")
    except TimestampParseError as e:
        print(f"{s!r:40} -> ERROR: {e}")

Worked example (executed output)

'10/Oct/2024:13:55:36 -0700'             -> 2024-10-10T20:55:36Z
'2024-10-09T11:23:45Z'                   -> 2024-10-09T11:23:45Z
'1700000000'                             -> 2023-11-14T22:13:20Z
'not-a-timestamp'                        -> ERROR: unrecognized timestamp format: 'not-a-timestamp'

The Apache-format conversion is the one worth checking by hand: 10/Oct/2024:13:55:36 -0700 means 13:55:36 in a timezone 7 hours behind UTC, so the UTC equivalent is 7 hours later, 2024-10-10T20:55:36Z, exactly what the code above produces (and note the date itself rolls over to the 10th, since 13:55 plus 7 hours crosses midnight).

Key points

• Format detection is done with a small regex per format rather than a generic "try everything and see what doesn't throw" approach; a bare try: parse_a() except: try: parse_b()... chain is harder to reason about because it's not obvious from reading it which format actually matched a given input.
• datetime.strptime(raw, "%d/%b/%Y:%H:%M:%S %z") handles the Apache format's fixed numeric offset (-0700) natively via the %z directive; there's no need to hand-parse the offset.
• Every branch converts to UTC with .astimezone(timezone.utc) before formatting, so the output format is always the same regardless of which input format was detected, which is the whole point of normalization.

Trade-offs & pitfalls

Timezone handling: an ISO 8601 string with no timezone at all (a naive timestamp) is deliberately rejected here rather than guessed at; silently assuming a missing offset means UTC (or local time) is a common source of subtle multi-hour errors when logs actually originated somewhere else, so the safer default is to require an explicit offset and fail loudly when one is missing. Epoch ambiguity: this implementation only accepts 9 or 10-digit epoch values, meaning seconds-since-epoch; real-world logs sometimes use milliseconds (13 digits) or microseconds (16 digits) instead, and a naive digit-count heuristic can misclassify one for another, producing a wildly wrong date (a valid-looking but nonsensical year like 1970 or 50000+) rather than an error. If your logs might emit sub-second-precision epoch values, that has to be handled as its own explicit branch, not silently folded into the seconds case.

Direct answer

Start from the config: read the logrotate (the standard Linux utility that rotates, compresses, and deletes log files on a schedule) stanza for this application and work out how many days of history it's actually supposed to retain, since "only 2 days survive" might be exactly what the config says, just not what anyone expected. If the config genuinely promises more than 2 days, the next question is whether rotation is happening more often than assumed, most commonly because it's triggered by file size, not purely by a daily schedule, and a burst of logging quietly burned through the retention budget faster than usual.

Structured elaboration

1. Read the actual config, don't assume it says what people remember. Find the stanza for this app (typically under /etc/logrotate.d/) and check rotate N (how many old copies to keep before deleting), and whether rotation is daily/weekly or size-triggered (e.g. size 100M). A config with rotate 14 genuinely only promises 14 rotation cycles, not 14 calendar days, those are the same thing only if rotation is purely time-based and never fires early.
2. Check whether rotation is size-triggered and could have fired more than once a day. This is the most common surprise: if the stanza has a size directive (or maxsize alongside daily), a burst of unusually verbose logging (a bug spamming warnings, a traffic spike) can trigger multiple rotations in a single day. If that happened, rotate 14 might only cover 3-4 calendar days instead of 14, and the config was never wrong, the assumption that "rotation count equals days" was.
3. Check when rotation actually last ran and how often. Logrotate records the last rotation timestamp per config stanza in a status file (commonly /var/lib/logrotate/status on newer Debian/Ubuntu packaging, or /var/lib/logrotate.status on some older systems, check whichever exists on this host). Comparing that against the timestamps on the surviving rotated files (ls -la --time-style=full-iso /var/log/myapp/*.gz) tells you the actual rotation cadence over the retention window, not the cadence the config implies.
4. Rule out something deleting files outside logrotate entirely. A disk-pressure cleanup cron job, a container image rebuild that wiped a non-persistent volume, or a manual cleanup someone ran and forgot about can all produce the exact same symptom as a rotation misconfiguration. Check for other scheduled jobs touching that directory (grep -r logrotate /etc/cron*, and anything else with find/rm against /var/log/myapp) before concluding it's purely a logrotate issue.
5. Dry-run the config to see what it would actually do right now. logrotate -d /etc/logrotate.d/myapp runs a dry run (debug mode: shows what actions would be taken without taking them), which is the fastest way to confirm your reading of the stanza matches what logrotate itself thinks it should do, catching a typo or an unexpected included/overriding config you missed on a manual read.

Worked example

# 1. What does the config actually promise?
cat /etc/logrotate.d/myapp
# e.g.:
#   /var/log/myapp/application.log {
#       daily
#       rotate 14
#       size 100M
#       compress
#   }
# This promises "up to 14 rotations, whichever of daily/100M triggers first"
# -- NOT unconditionally 14 calendar days.

# 2. When did each surviving rotation actually happen, and how big were they?
ls -la --time-style=full-iso /var/log/myapp/application.log*.gz

# 3. What does logrotate's own status file say about last-rotation timing?
cat /var/lib/logrotate/status 2>/dev/null || cat /var/lib/logrotate.status 2>/dev/null

# 4. Confirm the config parses the way you think it does, without applying it.
logrotate -d /etc/logrotate.d/myapp

If step 2's timestamps show several rotations within a single day around the time of a known traffic spike or noisy deploy, that's a strong, checkable signal that size 100M fired early and repeatedly, burning through the 14-rotation budget in far fewer than 14 days, exactly the "expected behavior, unexpected outcome" case rather than a misconfiguration.

What to change so it doesn't bite the next investigation

• If size-triggered rotation is the cause, either raise rotate N enough to cover your actual worst-case rotation cadence during a noisy period, or add maxage semantics via a longer retention window, or (often the real fix) ship logs off-host to a central store where retention isn't coupled to a single host's disk and a burst of local logging can't shrink your effective history.
• If the config is genuinely fine and the real gap is "logrotate's local retention was never meant to serve as your incident-investigation retention," that's a signal the two need to be decoupled: local rotation exists to bound disk usage, not to be the system of record for four-day-old incident evidence.
• Whatever the root cause, document the actual effective retention (in calendar days, under realistic worst-case log volume) somewhere a future investigator will find it before they hit the same surprise.

Trade-offs & pitfalls

• rotate N with a size trigger is a genuinely reasonable config for bounding disk usage; the mistake isn't the config, it's treating "N rotations" and "N days" as interchangeable when planning how far back an investigation can reach.
• Raising rotate N just enough to cover today's worst case doesn't protect against tomorrow's worse case (a bigger traffic spike, a noisier bug); if four-day-plus retention actually matters for incident response, local rotation on a single host is the wrong system to depend on at all.

Direct answer

Grok is the pattern-matching DSL (domain-specific language, a small purpose-built syntax rather than a general programming language) that Logstash's grok filter uses to name regex fragments and compose them, so you write field names instead of raw regex. The Logstash grok pattern below is illustrative configuration (not something this environment can execute against a real Logstash pipeline); the field boundaries it encodes are verified separately with an equivalent, executed Python regex against a real nginx combined log line.

Approach

Logstash grok pattern

%{IPORHOST:client_ip} - %{USER:ident} \[%{HTTPDATE:timestamp}\] "%{WORD:method} %{DATA:path} %{DATA:protocol}" %{NUMBER:status} %{NUMBER:bytes_sent} "%{DATA:referrer}" "%{DATA:user_agent}"

Each %{PATTERN:field_name} is a named, reusable regex fragment from grok's built-in pattern library: %{IPORHOST} matches an IP address or hostname, %{USER} matches a username token, %{HTTPDATE} matches Apache's bracketed date format, %{WORD} matches one alphabetic token, and %{NUMBER} matches a numeric string, each expanding to a pre-built regex fragment so you don't have to write it by hand. %{DATA} is grok's non-greedy "anything" pattern, used here for path, protocol, referrer, and user_agent because those fields can contain almost any character. Note that grok's own built-in COMBINEDAPACHELOG pattern names the trailing HTTP/1.1 token httpversion and only captures the version number, not the scheme; since the question asks specifically for a field named protocol, this pattern captures the whole HTTP/1.1 token (scheme and version together) under that name instead, which is the more literal reading of "protocol."

Verifying the field boundaries (executed)

import re

# Same field boundaries as the grok pattern
# %{IPORHOST:client_ip} - %{USER:ident} \[%{HTTPDATE:timestamp}\]
# "%{WORD:method} %{DATA:path} %{DATA:protocol}"
# %{NUMBER:status} %{NUMBER:bytes_sent} "%{DATA:referrer}" "%{DATA:user_agent}"
PATTERN = re.compile(
    r'^(?P<client_ip>\S+) - (?P<ident>\S+) '
    r'\[(?P<timestamp>[^\]]+)\] '
    r'"(?P<method>[A-Z]+) (?P<path>\S+) (?P<protocol>[A-Z]+/[\d.]+)" '
    r'(?P<status>\d+) (?P<bytes_sent>\d+|-) '
    r'"(?P<referrer>[^"]*)" '
    r'"(?P<user_agent>[^"]*)"$'
)

line = ('203.0.113.5 - - [10/Oct/2024:13:55:36 -0700] '
        '"GET /search?q=test%20query HTTP/1.1" 200 5231 '
        '"https://example.com/" '
        '"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36"')

m = PATTERN.match(line)
if m:
    for k, v in m.groupdict().items():
        print(f"{k}: {v}")
else:
    print("no match")

Worked example (executed output)

client_ip: 203.0.113.5
ident: -
timestamp: 10/Oct/2024:13:55:36 -0700
method: GET
path: /search?q=test%20query
protocol: HTTP/1.1
status: 200
bytes_sent: 5231
referrer: https://example.com/
user_agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36

Key points

• Query strings in the path: %{DATA:path} is non-greedy, so it stops at the first space rather than trying to consume the rest of the line; a query string like ?q=test%20query stays part of the path field intact, exactly as shown above (/search?q=test%20query). If you need path and query as separate fields, add a dissect or mutate step after the grok match to split on the first ?.
• Percent-encoding: neither grok nor this regex decodes %20 into a space; that's expected; percent-encoding is part of the raw URL and decoding it is a separate, deliberate step (only do it if you actually need the decoded form for display or analysis, since the encoded form is what the server actually received).
• Very long user agents and mapping explosion: in Elasticsearch, a text or default-mapped keyword field indexes every unique value it sees; browser and bot user-agent strings are extremely high-cardinality (having a very large number of distinct values) and some are very long, which can blow up index size and even hit Elasticsearch's field-length limits. The practical mitigations are: map user_agent as keyword with ignore_above set (so overlong values are stored but not indexed for aggregation), truncate the field before indexing if you only need it for display, and, if you need to group by user agent at all, index a hash of the full string instead of the raw string for aggregation purposes.
• Naming protocol vs. a library's default field name: this is a small but real pitfall in its own right. A team pulling in a stock COMBINEDAPACHELOG-style pattern will get httpversion, not protocol, and a downstream query or dashboard written against "protocol" will silently return nothing until someone notices the field doesn't exist. When a spec (a question, a ticket, a schema doc) names a field explicitly, match that name exactly, or add an explicit rename/alias step, rather than assuming a library's default naming is close enough.

Trade-offs & pitfalls

The main pitfall with grok specifically is that a malformed line (one that doesn't match the pattern at all) produces no match and typically gets tagged as a parse failure rather than partially parsed; a production pipeline needs a fallback path for those lines rather than silently dropping them. The other common mistake is treating query strings as low-cardinality: a path with a highly variable query string (a session token, a timestamp) indexed as a single keyword field will itself cause the same kind of cardinality blowup as an unbounded user-agent field, so the same truncate-or-split discipline usually needs to apply to path as well, not just to user_agent.

Direct answer

Stream each file line by line rather than reading it into memory, filter to the matching request_id and timestamp range as you go, and merge the per-file streams with a k-way merge, using a min-heap (a small structure that always exposes the smallest of the items it holds) keyed by timestamp, so the combined output comes out globally chronological without ever holding more than one buffered record per file at once.

Approach

import json
import heapq
from datetime import datetime


def _parse_ts(raw):
    return datetime.fromisoformat(raw.replace("Z", "+00:00"))


def _file_matches(path, request_id, start_ts, end_ts):
    """Stream one file line by line. Assumes each file is internally
    time-ordered (true of an append-only log file), so this generator
    yields matching events in ascending timestamp order for THIS file.
    Never holds more than the current line in memory.
    """
    with open(path, "r") as f:
        for line in f:
            line = line.strip()
            if not line:
                continue
            try:
                rec = json.loads(line)
            except json.JSONDecodeError:
                continue
            if rec.get("request_id") != request_id:
                continue
            raw_ts = rec.get("ts")
            if raw_ts is None:
                continue
            try:
                event_ts = _parse_ts(raw_ts)
            except ValueError:
                continue
            if start_ts <= event_ts <= end_ts:
                rec["_ts_parsed"] = event_ts
                yield rec


def extract_events(file_paths, request_id, start_ts, end_ts):
    """Yield events with the given request_id whose timestamp falls in
    [start_ts, end_ts], in chronological order, across multiple large
    NDJSON log files, without loading any file fully into memory.

    Each file is scanned by its own generator (bounded to one open line
    at a time); a min-heap does a k-way merge across those generators so
    only one buffered record per file is held at once, not all matches.
    Memory is O(number of files), not O(file size) or O(match count).
    """
    heap = []
    iterators = [iter(_file_matches(p, request_id, start_ts, end_ts)) for p in file_paths]
    for idx, it in enumerate(iterators):
        first = next(it, None)
        if first is not None:
            heapq.heappush(heap, (first["_ts_parsed"], idx, first))

    while heap:
        ts, idx, rec = heapq.heappop(heap)
        del rec["_ts_parsed"]
        yield rec
        nxt = next(iterators[idx], None)
        if nxt is not None:
            heapq.heappush(heap, (nxt["_ts_parsed"], idx, nxt))


if __name__ == "__main__":
    import os

    file_a = "/tmp/loganalysis_b1_s13_a.ndjson"
    file_b = "/tmp/loganalysis_b1_s13_b.ndjson"

    # file_a and file_b are each individually time-ordered, as a real
    # per-host or per-service log file would be, even though the SET of
    # files is not globally ordered relative to each other.
    with open(file_a, "w") as f:
        f.write(json.dumps({"ts": "2025-01-01T00:00:01Z", "request_id": "req-1", "service": "C", "msg": "too_early"}) + "\n")
        f.write(json.dumps({"ts": "2025-01-01T00:00:02Z", "request_id": "req-1", "service": "A", "msg": "start"}) + "\n")
        f.write(json.dumps({"ts": "2025-01-01T00:00:09Z", "request_id": "req-2", "service": "A", "msg": "other_request"}) + "\n")
        f.write("not valid json\n")
        f.write(json.dumps({"ts": "2025-01-01T00:00:20Z", "request_id": "req-1", "service": "A", "msg": "too_late"}) + "\n")

    with open(file_b, "w") as f:
        f.write(json.dumps({"ts": "2025-01-01T00:00:05Z", "request_id": "req-1", "service": "B", "msg": "middle"}) + "\n")

    start = _parse_ts("2025-01-01T00:00:02Z")
    end = _parse_ts("2025-01-01T00:00:10Z")

    for rec in extract_events([file_a, file_b], "req-1", start, end):
        print(rec)

    os.remove(file_a)
    os.remove(file_b)

Worked example (executed output)

{'ts': '2025-01-01T00:00:02Z', 'request_id': 'req-1', 'service': 'A', 'msg': 'start'}
{'ts': '2025-01-01T00:00:05Z', 'request_id': 'req-1', 'service': 'B', 'msg': 'middle'}

file_a and file_b are individually time-ordered (as a real append-only log file would be), but the two files are not ordered relative to each other, and file_a even has an out-of-range line, a wrong-request-id line, and a malformed line mixed in. The output above still comes out correctly filtered and in chronological order across both files.

Key points

• Memory usage is O(number of files), not O(file size) or O(number of matches): at any moment, the heap holds at most one buffered record per file, since each file is its own generator that only produces its next matching record when asked.
• The k-way merge relies on one precondition worth stating explicitly: each individual file must already be time-ordered internally. That's a safe assumption for a normal append-only application log, but it would need to be checked (or the approach would need to change) for a log source that writes out of order within a single file.
• extract_events is itself a generator (it yields rather than returning a list), so a caller can start consuming matching events immediately and stop early if it only needs the first few, rather than waiting for the entire multi-file scan to finish.

Complexity

Let N be the total number of matching events across all files and k be the number of files. Each heap push/pop is O(log k), and there are O(N) of them (one per yielded event, plus refills), so total time is O(N log k). Space is O(k) for the heap itself, plus the fixed per-line buffer each open file uses while being read, which is independent of file size.

Edge cases

• Malformed JSON lines: skipped rather than raising, so one corrupt line doesn't abort the entire scan (shown above: file_a's "not valid json" line is silently passed over).
• A file with no matches at all: its generator is simply exhausted immediately and it drops out of the heap; the merge continues correctly with the remaining files.
• Ties on identical timestamps across files: the heap comparison falls through to the file index as a tiebreaker, so results are still deterministic (files earlier in the input list sort first on an exact tie) rather than raising a comparison error on the underlying dict.
• A file that isn't actually time-ordered internally: this breaks the merge's chronological guarantee silently (each file's own stream would emit an out-of-order record without the heap detecting it), which is worth flagging explicitly rather than assuming away.

Trade-offs & pitfalls

A simpler alternative, collect every match into a list and sort once at the end, is easier to write and is fine when you expect a bounded, small number of matches for one request_id (usually true; a single request rarely touches millions of log lines). The heap-based merge shown here is the more defensible answer for a "must stream, must not load fully into memory" prompt because it doesn't rely on that assumption: it stays memory-bounded even in the pathological case where one request_id matches a huge number of events, which the simpler collect-and-sort approach would not.

Direct answer

Match each field positionally with a PCRE (Perl Compatible Regular Expression, the regex flavor used by grep -P, Perl, and Python's re module) pattern using named groups, one group per field. Named groups make the extraction self-documenting and let downstream code read match["client_ip"] instead of a numbered \1.

Approach

import re

PATTERN = re.compile(
    r'^(?P<client_ip>\S+) \S+ (?P<user>\S+) '
    r'\[(?P<timestamp>[^\]]+)\] '
    r'(?P<method>[A-Z]+) (?P<path>\S+) (?P<protocol>[A-Z]+/\d\.\d) '
    r'(?P<status>\d{3}) (?P<bytes>\d+|-)$'
)

line = '127.0.0.1 - frank [10/Oct/2024:13:55:36 -0700] GET /index.html HTTP/1.1 200 2326'

m = PATTERN.match(line)
if m:
    for k, v in m.groupdict().items():
        print(f"{k}: {v}")
else:
    print("no match")

Worked example (executed output)

client_ip: 127.0.0.1
user: frank
timestamp: 10/Oct/2024:13:55:36 -0700
method: GET
path: /index.html
protocol: HTTP/1.1
status: 200
bytes: 2326

The same named-group syntax works directly with grep -P on the command line (grep -oP prints only the matched text), and the equivalent extraction with awk, splitting on whitespace since this log line has no embedded quoted fields, looks like:

LINE='127.0.0.1 - frank [10/Oct/2024:13:55:36 -0700] GET /index.html HTTP/1.1 200 2326'
echo "$LINE" | awk '{
  ip=$1; user=$3;
  ts=$4" "$5; gsub(/[\[\]]/,"",ts);
  printf "client_ip=%s user=%s timestamp=%s method=%s path=%s protocol=%s status=%s bytes=%s\n", ip, user, ts, $6, $7, $8, $9, $10
}'

which prints client_ip=127.0.0.1 user=frank timestamp=10/Oct/2024:13:55:36 -0700 method=GET path=/index.html protocol=HTTP/1.1 status=200 bytes=2326, matching the Python extraction field for field. awk works here specifically because this log line has no spaces inside any field; a format with a quoted user-agent field (spaces included) would break plain whitespace splitting and need the regex approach instead.

Trade-offs & pitfalls

Timestamp parsing caveats: the bracketed timestamp 10/Oct/2024:13:55:36 -0700 is Apache's own format, not ISO 8601, so a generic date parser will not accept it as-is; you need a format string like %d/%b/%Y:%H:%M:%S %z (Python strptime) that matches it exactly. The trailing -0700 is a fixed UTC offset, not a named timezone, and does not account for daylight saving time changes on its own; if you're aggregating log lines from hosts in different timezones, convert every timestamp to UTC immediately after parsing rather than comparing the raw offset strings.

A second pitfall: this pattern assumes the log line has no quoted fields (no referrer, no user-agent), which is why it splits cleanly on whitespace. The moment a field can contain a space (a real Apache "combined" format log includes a quoted user-agent), whitespace-based extraction breaks and you need to match the quotes explicitly, as covered in the ELK grok-pattern version of this same problem.