Módulo 3: Observability As Sli Input

4. Manos a la obra: logs reales con `jq`

Siguiente →

Descripción

Errors: 3.0 es todo lo que la lección 3 pudo decir sobre las fallas del batch — un conteo, sin ningún detalle. Esta lección abre esas tres fallas: qué requestId específico corresponde a cada una, y qué mensaje de error real dejó validate_manifest() en cada caso. La consulta a CloudWatch Logs que trae esos datos es, como en la lección anterior, representativa —la razón es idéntica: sin LOCALSTACK_AUTH_TOKEN, LocalStack no arranca en este entorno—. Lo que cambia en esta lección, y es la pieza central: una vez que esa salida (representativa, pero fiel al formato real que CloudWatch Logs produce) se guarda en un archivo, jq la procesa de verdad — el binario corrió, en este mismo entorno, para producir cada bloque "Qué esperar" de la segunda mitad de esta lección.

Conexión con el módulo

La lección 2 prometió que los logs contestan "¿cuáles, específicamente, fueron los eventos malos, y por qué?" — esta lección lo demuestra con las tres invocaciones fallidas del batch de la lección 3, identificadas por requestId, cada una con su mensaje de error real. La lección 5 va a tomar uno de esos tres requestId —el de la posición 17— y seguirlo con una traza completa en Jaeger.

Paso 1 — Consultando los logs reales de las tres fallas

Cada invocación de process-shipment-manifest escribe en /aws/lambda/process-shipment-manifest (el nombre de grupo de logs que aws-core-services-guide, Módulo 6, ya estableció como la convención automática de Lambda: /aws/lambda/<nombre-de-la-función>). Dos líneas por invocación fallida son las que importan aquí: el print(f"Invalid manifest {key}: {errors}") real de lambda_handler justo antes de relanzar la excepción, y la línea REPORT que el runtime de Lambda agrega automáticamente al final de cada invocación, con Status: error\tError Type: Unhandled quand la invocación no capturó su excepción — exactamente el comportamiento que aws-serverless-and-containers-guide ya confirmó para este mismo Lambda.

Un patrón de filtro con dos alternativas (?"..." ?"...", la sintaxis OR de CloudWatch Logs Insights) trae ambas líneas en una sola consulta:

awslocal logs filter-log-events \
  --log-group-name /aws/lambda/process-shipment-manifest \
  --filter-pattern '?"Invalid manifest" ?"Status: error"' \
  --start-time 2026-08-14T14:00:00Z \
  --end-time 2026-08-14T15:00:00Z

Qué esperar (representativo — CloudWatch Logs, confirmado en el plan Hobby de LocalStack; guarda esta salida exactamente como observability/manifest-log-events.json, la vas a necesitar en el Paso 2):

{
    "events": [
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732801005,
            "message": "Invalid manifest manifests/year=2026/month=08/batch/05-shipment-4471-manifest.txt: ['missing required field: weightKg']\n",
            "ingestionTime": 1786732801512,
            "eventId": "38234501234567890123456789012345678901"
        },
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732801041,
            "message": "REPORT RequestId: a47f3e21-8b6a-4c9d-9f12-3d8e7b1a2c44\tDuration: 38.47 ms\tBilled Duration: 39 ms\tMemory Size: 128 MB\tMax Memory Used: 44 MB\tStatus: error\tError Type: Unhandled\n",
            "ingestionTime": 1786732801530,
            "eventId": "38234501234567890123456789012345678902"
        },
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732808211,
            "message": "Invalid manifest manifests/year=2026/month=08/batch/12-shipment-4472-manifest.txt: ['missing required field: carrier']\n",
            "ingestionTime": 1786732808698,
            "eventId": "38234501234567890123456789012345678903"
        },
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732808253,
            "message": "REPORT RequestId: f3c91a08-2e4d-4b7f-8a3c-5e9d1f6b8a72\tDuration: 41.02 ms\tBilled Duration: 42 ms\tMemory Size: 128 MB\tMax Memory Used: 45 MB\tStatus: error\tError Type: Unhandled\n",
            "ingestionTime": 1786732808710,
            "eventId": "38234501234567890123456789012345678904"
        },
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732814977,
            "message": "Invalid manifest manifests/year=2026/month=08/batch/17-shipment-4473-manifest.txt: ['weightKg must be numeric']\n",
            "ingestionTime": 1786732815488,
            "eventId": "38234501234567890123456789012345678905"
        },
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "timestamp": 1786732815012,
            "message": "REPORT RequestId: c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58\tDuration: 35.88 ms\tBilled Duration: 36 ms\tMemory Size: 128 MB\tMax Memory Used: 44 MB\tStatus: error\tError Type: Unhandled\n",
            "ingestionTime": 1786732815499,
            "eventId": "38234501234567890123456789012345678906"
        }
    ],
    "searchedLogStreams": [
        {
            "logStreamName": "2026/08/14/[$LATEST]4a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d",
            "searchedCompletely": true
        }
    ]
}

Seis eventos, dos por cada una de las tres invocaciones fallidas —la línea de validación que explica el "por qué", y la línea REPORT que trae el requestId—, en el mismo orden en que ocurrieron (posiciones 5, 12, 17 del batch de la lección 3).

Paso 2 — jq, corriendo de verdad, en tres pasos

A partir de aquí, todo corrió: jq no depende de LocalStack, procesa el archivo que acabas de guardar sin ninguna limitación de este entorno.

Paso 2a — Los tres requestId, extraídos de las líneas REPORT con una expresión regular:

jq -r '.events[] | select(.message | contains("Status: error")) | .message | capture("RequestId: (?<requestId>[a-f0-9-]+)") | .requestId' observability/manifest-log-events.json

Qué esperar (literal — corrido con jq en este entorno):

a47f3e21-8b6a-4c9d-9f12-3d8e7b1a2c44
f3c91a08-2e4d-4b7f-8a3c-5e9d1f6b8a72
c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58

Paso 2b — Las tres razones de validación, extraídas de las líneas Invalid manifest:

jq -r '.events[] | select(.message | contains("Invalid manifest")) | .message' observability/manifest-log-events.json

Qué esperar (literal):

Invalid manifest manifests/year=2026/month=08/batch/05-shipment-4471-manifest.txt: ['missing required field: weightKg']

Invalid manifest manifests/year=2026/month=08/batch/12-shipment-4472-manifest.txt: ['missing required field: carrier']

Invalid manifest manifests/year=2026/month=08/batch/17-shipment-4473-manifest.txt: ['weightKg must be numeric']

(Las líneas en blanco son el propio salto de línea que print() deja al final de cada mensaje — un detalle real del formato de log, no un error de este comando.)

Paso 2c — Combinando ambas en un solo objeto por invocación fallida:

jq '
  (.events | map(select(.message | contains("Invalid manifest"))) | map(.message | rtrimstr("\n"))) as $reasons
  | (.events | map(select(.message | contains("Status: error"))) | map(.message | capture("RequestId: (?<id>[a-f0-9-]+)").id)) as $ids
  | [range(0; $ids | length) | {requestId: $ids[.], reason: $reasons[.]}]
' observability/manifest-log-events.json

Qué esperar (literal):

[
  {
    "requestId": "a47f3e21-8b6a-4c9d-9f12-3d8e7b1a2c44",
    "reason": "Invalid manifest manifests/year=2026/month=08/batch/05-shipment-4471-manifest.txt: ['missing required field: weightKg']"
  },
  {
    "requestId": "f3c91a08-2e4d-4b7f-8a3c-5e9d1f6b8a72",
    "reason": "Invalid manifest manifests/year=2026/month=08/batch/12-shipment-4472-manifest.txt: ['missing required field: carrier']"
  },
  {
    "requestId": "c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58",
    "reason": "Invalid manifest manifests/year=2026/month=08/batch/17-shipment-4473-manifest.txt: ['weightKg must be numeric']"
  }
]

Este es, literalmente, el detalle que Errors: 3.0 no podía dar: tres requestId distintos, tres razones distintas, cada una trazable hasta la línea exacta de validate_manifest() que la produjo. Guarda el requestId c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58 —la posición 17— para la lección 5, que lo sigue con una traza completa.

Errores comunes

Confundir "representativo" (la consulta a CloudWatch) con "representativo" (el resultado de jq) — son dos cosas distintas en esta lección. Qué pasa: alguien, al leer que el Paso 1 es representativo, asume que el Paso 2 también lo es. Cómo detectarlo: si tu explicación de esta lección dice "todo esto es representativo" sin distinguir el paso 1 del paso 2. Cómo corregirlo: el Paso 1 (la consulta a CloudWatch) es representativo porque depende de LocalStack, que no arranca en este entorno. El Paso 2 (jq sobre el archivo ya guardado) es completamente real —jq no depende de ningún servicio de AWS, corrió de verdad, y el archivo manifest-log-events.json que produce el Paso 1 es el único punto de conexión entre ambos.

Escribir una expresión jq distinta y esperar el mismo resultado exacto de esta lección (de no entender qué hace capture). Qué pasa: alguien escribe una expresión propia para extraer el requestId —por ejemplo, con split(": ") en vez de capture()— y el resultado no coincide con el de esta lección. Cómo detectarlo: si tu salida del Paso 2a tiene texto adicional (como RequestId: incluido) en vez de solo el UUID. Cómo corregirlo: capture("RequestId: (?<requestId>[a-f0-9-]+)") usa una expresión regular con un grupo nombrado (?<requestId>) que extrae solo la parte que coincide con [a-f0-9-]+ —caracteres hexadecimales y guiones— después del texto literal "RequestId: ". Cualquier expresión que no aísle exactamente ese patrón va a incluir texto de más o de menos.

Tratar los tres requestId extraídos como si fueran arbitrarios, sin conexión con la lección 3 (de perder el hilo del batch fijo). Qué pasa: alguien procesa esta lección de forma aislada, sin notar que los tres requestId corresponden exactamente a las posiciones 5, 12 y 17 del batch de la lección anterior. Cómo detectarlo: si no puedes decir, de memoria, qué posición del batch de 20 corresponde a c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58. Cómo corregirlo: la lección 1 de este módulo ya lo advirtió — este módulo corre sobre un único batch fijo, leído con tres instrumentos. El requestId c8e42d15-... no es un dato nuevo; es la misma invocación fallida número 17 de la lección 3, ahora identificada con precisión.

Ejercicios

Ejercicio 1 — Escribe, sin ejecutarlo todavía, un comando jq que cuente cuántas invocaciones fallidas hay en el archivo, sin extraer ningún detalle. Usa el mismo archivo manifest-log-events.json.

Ver solución 
jq '[.events[] | select(.message | contains("Status: error"))] | length' observability/manifest-log-events.json

Este comando produce 3 — el mismo número que Errors: 3.0 ya dio en la lección 3, ahora confirmado contando directamente las líneas REPORT con Status: error en los logs, en vez de leer un agregado de CloudWatch. Es una forma útil de verificar, de manera independiente, que la métrica y el log cuentan la misma historia.

Ejercicio 2 — Modifica el comando del Paso 2b para que, en vez de imprimir el mensaje completo, extraiga solo la lista de errores entre corchetes (por ejemplo, ['missing required field: weightKg']). Pista: usa capture() con una expresión regular que capture todo lo que está entre [ y ].

Ver solución 
jq -r '.events[] | select(.message | contains("Invalid manifest")) | .message | capture("(?<errors>\\[.*\\])") | .errors' observability/manifest-log-events.json

Con el archivo de esta lección, produce:

['missing required field: weightKg']
['missing required field: carrier']
['weightKg must be numeric']

El patrón \\[.*\\] (los corchetes escapados con \\, porque son caracteres especiales en una expresión regular) captura todo lo que hay entre el primer [ y el último ] de la línea — exactamente la representación en texto de la lista Python errors que validate_manifest() construyó.

Ejercicio 3 — Explica por qué el Paso 2c usa range(0; $ids | length) en vez de, por ejemplo, zip($ids; $reasons) (si tu versión de jq la tiene) o cualquier otra forma de combinar dos listas. ¿Qué garantiza que $ids[.] y $reasons[.] correspondan siempre a la misma invocación, en el mismo índice?

Ver solución

La garantía no viene de range() en sí —viene de que ambas listas, $ids y $reasons, se construyen filtrando el mismo arreglo .events en el mismo orden en que aparece en el archivo, y ese archivo, a su vez, preserva el orden cronológico real en que CloudWatch Logs recibió cada línea (posición 5 antes que 12, antes que 17). Como cada invocación fallida escribió exactamente una línea Invalid manifest seguida, poco después, de exactamente una línea REPORT con Status: error, filtrar cada tipo de línea por separado preserva el mismo orden relativo en ambas listas resultantes — el elemento en el índice 0 de $ids corresponde, por construcción, al elemento en el índice 0 de $reasons. Esta correspondencia por posición es frágil en general (se rompería si alguna invocación fallara sin dejar ambas líneas, o si el orden cronológico no se preservara) — una razón más para no tratar este truco como una técnica universal de jq, sino como algo válido específicamente para la estructura de este archivo.

Resumen y siguiente paso

Esta lección abrió las tres fallas que la lección 3 solo pudo contar: con una consulta representativa a CloudWatch Logs (misma razón de siempre: sin LOCALSTACK_AUTH_TOKEN, LocalStack no arranca aquí) guardaste el detalle real de las seis líneas relevantes, y con jq —corrido de verdad, en tres pasos progresivos— extrajiste los tres requestId, las tres razones de validación, y los combinaste en un solo objeto por invocación fallida. Confirmaste, además, que el conteo de líneas con error (3) coincide exactamente con el Errors: 3.0 de la lección anterior — la métrica y el log cuentan la misma historia, con distinto nivel de detalle.

Antes de avanzar deberías poder: explicar la diferencia entre lo representativo (el Paso 1) y lo real (el Paso 2) de esta lección; recitar los tres requestId extraídos, con su razón de fallo correspondiente; y modificar una expresión capture() simple para extraer un fragmento distinto de un mensaje de log.

La lección 5 toma el requestId de la posición 17 —c8e42d15-9a3b-4f8e-b6c1-7d2a4e9f3b58— y lo sigue con una traza real de OpenTelemetry, mostrando en qué paso exacto del flujo upload → Lambda → DynamoDB esa invocación se cortó.

Recursos

  1. jq Manual — capture — la función de esta lección para extraer datos con expresiones regulares con nombre.
  2. jq Manual — select — el filtro que separa las líneas REPORT de las líneas Invalid manifest en esta lección.
  3. AWS CLI — logs filter-log-events Command Reference — la referencia oficial del comando representativo del Paso 1, incluida la sintaxis de patrones ?"..." ?"...".
  4. LocalStack Docs — CloudWatch Logs — confirmación del plan Hobby para el servicio de logs.
  5. Este mismo repositorio, Módulo 3, lección 3 (03-hands-on-real-metrics-from-the-inherited-lambda.md) — el batch fijo cuyas tres fallas esta lección abre en detalle.
← Anterior3. Manos a la obra: métricas reales del Lambda heredadoSiguiente →5. Manos a la obra: trazas con OpenTelemetry y Jaeger