Status: PROVISIONAL — ASU-specific loss confirmed, root cause unknown Date: 2026-03-10 incident, 2026-03-16 re-analysis JIRA: ENG-3349 Previous RCA: Gist d81250648d (superseded by this document)

2,798 of 300,839 intel requests on March 10 never had facts created (~0.93%). Re-analysis of 6 sample batches (404 IRs) using correct identifiers shows:

• event-recorder: 404/404 — 0% loss¹
• AIPT: 404/404 — 0% loss²
• ASU: 388/404 — 3.96% loss, consistent across every batch³

The loss is ASU-specific. The previous RCA incorrectly attributed loss to all consumers due to a search methodology error⁴.

The error: consumer logs index messages by correlation_id and batch_id, not intel_request_id. The original searched by intel_request_id, found nothing, and concluded messages were lost. In reality, the messages were there under different identifiers⁶.

Cody provided intel_request_id values. Consumer logs don't contain this field on processing lines⁷. The mapping is:

intel_request_id  →  DB metadata column[^db-query]
  └→ correlation_id  (unique per location, logged as CID)
  └→ batch_id        (shared per API request, = original correlation_id)[^batch-id-code]

10 sample IRs mapped to 6 distinct batches, all org 9de5d801⁸.

Each processed message produces exactly 2 log lines (Processing... + Processed...) from the shared amqp-consumer library⁹. Counting message_type:exact("intel_requests.created") lines per batch_id per service, divided by 2, gives IRs processed¹⁰.

Vector's VRL pipeline¹¹ extracts IDs from unstructured log text into structured VictoriaLogs fields:

ASU logs (Intel Request {id}): Received power_status.updated...¹⁵ on discard lines — Vector extracts this into intel_request_id. But the generic Processing/Processed message type: intel_requests.created lines⁹ don't contain that pattern, so intel_request_id is absent on the lines that prove message delivery.

This creates a trap: searching intel_request_id:exact("56a219a6...") finds ASU's power_status.updated discard (hours later, different batch) but misses the intel_requests.created processing entirely.

Event-recorder never logs individual IR IDs at all¹⁶ — it only stores event_type, correlation_id, and organization_id as structured metadata.

The root cause of ASU's ~4% loss is unidentified. Theories (all unverified):

1. Silent discard in ASU handler — an early return path that doesn't log¹⁵
2. Backpressure — ASU processing time (0.12-0.15s/msg) is 3x slower than event-recorder (0.05s/msg)
3. Queue configuration — different prefetch/QoS or replica count

1. Deploy _on_message logging (MR 17¹⁷) on ASU — determines whether messages reach ASU's callback at all
2. Audit ASU handler for silent drops — check all return paths in intel_requests.created processing
3. Compare ASU queue config to event-recorder and AIPT (prefetch, replicas, resource limits)

service_name:exact("asset-status-updater") AND "Received message" AND "intel_requests.created"

Compare count to event-recorder's count for the same time window. If equal → loss is post-delivery (handler bug). If lower → loss is pre-delivery (RabbitMQ/queue issue).

• Reverted MR 47⁵ — restored correlation_id as batch_id (traceability fix)
• MR 17¹⁷ still open — diagnostic logging, pending Diego's review of shutdown protection

• ASU batch c2a627b3 — expect 336 lines
• event-recorder batch c2a627b3 — expect 348 lines