Engarde : Parse envoy and istio-proxy access logs like a champ

Engarde : Parse Envoy and istio-proxy logs like a champ

Envoy Proxy

Istio Service Mesh

Envoy Access Logs

[%START_TIME%] "%REQ(:METHOD)% %REQ(X-ENVOY-ORIGINAL-PATH?:PATH)% %PROTOCOL%" %RESPONSE_CODE% %RESPONSE_FLAGS% %BYTES_RECEIVED% %BYTES_SENT% %DURATION% %RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)% "%REQ(X-FORWARDED-FOR)%" "%REQ(USER-AGENT)%" "%REQ(X-REQUEST-ID)%" "%REQ(:AUTHORITY)%" "%UPSTREAM_HOST%"\n
[2016-04-15T20:17:00.310Z] "POST /api/v1/locations HTTP/2" 204 - 154 0 226 100 "10.0.35.28" "nsq2http" "cc21d9b0-cf5c-432b-8c7e-98aeb7988cd2" "locations" "tcp://10.0.2.1:80"

Introducing Engarde

[%START_TIME%] \”%REQ(:METHOD)% %REQ(X-ENVOY-ORIGINAL-PATH?:PATH)% %PROTOCOL%\” %RESPONSE_CODE% %RESPONSE_FLAGS% ”%DYNAMIC_METADATA(istio.mixer:status)%\” %BYTES_RECEIVED% %BYTES_SENT% %DURATION% %RESP(X-ENVOY-UPSTREAM-SERVICE-TIME)% \”%REQ(X-FORWARDED-FOR)%\” \”%REQ(USER-AGENT)%\” \”%REQ(X-REQUEST-ID)%\” \”%REQ(:AUTHORITY)%\” \”%UPSTREAM_HOST%\” %UPSTREAM_CLUSTER% %UPSTREAM_LOCAL_ADDRESS% %DOWNSTREAM_LOCAL_ADDRESS% %DOWNSTREAM_REMOTE_ADDRESS% %REQUESTED_SERVER_NAME%\n

Getting Started with Engarde

Sample

echo '[2016–04–15T20:17:00.310Z] "POST /api/v1/locations HTTP/2" 204–154 0 226 100 "10.0.35.28" "nsq2http" "cc21d9b0-cf5c-432b-8c7e-98aeb7988cd2" "locations" "tcp://10.0.2.1:80"' | engarde | jq
{
"authority": "locations",
"bytes_received": "154",
"bytes_sent": "0",
"duration": "226",
"method": "POST",
"protocol": "HTTP\/2",
"request_id": "cc21d9b0-cf5c-432b-8c7e-98aeb7988cd2",
"response_flags": "-",
"status_code": "204",
"timestamp": "2016\u201304\u201315T20:17:00.310Z",
"upstream_service": "tcp:\/\/10.0.2.1:80",
"upstream_service_time": "100",
"uri_path": "\/api\/v1\/locations",
"user_agent": "nsq2http",
"original_message": "[2016\u201304\u201315T20:17:00.310Z] \"POST \/api\/v1\/locations HTTP\/2\" 204\u2013154 0 226 100 \"10.0.35.28\" \"nsq2http\" \"cc21d9b0-cf5c-432b-8c7e-98aeb7988cd2\" \"locations\" \"tcp:\/\/10.0.2.1:80\""
}
kubectl logs -f foo-app-1 -c istio-proxy | engarde — use-istio | jq
{
“authority”: “hello-world”,
“bytes_received”: “148”,
“bytes_sent”: “171”,
“duration”: “4”,
“method”: “GET”,
“protocol”: “HTTP/1.1”,
“request_id”: “c0ce81db-4f5a-9134–8a5c-f8c076c91652”,
“response_flags”: “-”,
“status_code”: “200”,
“timestamp”: “2019–09–03T05:37:41.341Z”,
“upstream_service”: “192.168.89.50:9001”,
“upstream_service_time”: “3”,
“upstream_cluster”: “outbound|80||hello-world.default.svc.cluster.local”,
“upstream_local”: “-”,
“downstream_local”: “10.97.86.53:80”,
“downstream_remote”: “192.168.167.113:39953”,
“uri_path”: “/index”,
“user_agent”: “-”,
“mixer_status”: “-”,
“original_message”: “[2019–09–03T05:37:41.341Z] \”GET /index HTTP/1.1\” 200 — \”-\” 148 171 4 3 \”-\” \”-\” \”c0ce81db-4f5a-9134–8a5c-f8c076c91652\” \”hello-world\” \”192.168.89.50:9001\” outbound|80||hello-world.default.svc.cluster.local — 10.97.86.53:80 192.168.167.113:39953 -”
}

JQ + Engarde

kubectl logs -f foo-app-1 -c istio-proxy | engarde — use-istio | jq -c ‘select( .status_code = 200) | {log: .original_message, URI: .uri_path, UpstreamCluster: .upstream_cluster}’ | jq
{
“log”: “[2019–09–06T19:11:40.645Z] \”GET /v1/health/service/xyz?index=0&wait=10s HTTP/1.1\” 500 — \”-\” 0 23 0 0 \”-\” \”Python-urllib/2.7\” \”83484d3a-fedb-96f5-a653–1c38fa1ac2e4\” \”10.15.12.33:8500\” \”10.15.12.33:8500\” PassthroughCluster — 10.15.12.33:8500 192.168.89.3:34780 -”,
“URI”: “/v1/health/foobar”,
“UpstreamCluster”: “PassthroughCluster”
}
{
“log”: “[2019–09–06T19:11:42.218Z] \”GET /metrics HTTP/1.1\” 200 — \”-\” 0 0 1 0 \”-\” \”Prometheus/2.9.1\” \”e8810c98–9e10–9b2c-837e-987ec3ed3614\” \”192.168.89.3:9001\” \”127.0.0.1:9001\” inbound|80|foo-worker|hello-world.foo-namespace.svc.cluster.local — 192.168.89.3:9001 192.168.167.109:53458 -”,
“URI”: “/metrics”,
“UpstreamCluster”: “inbound|80|foo-worker|hello-world.foo-namespace.svc.cluster.local”
}
{
“log”: “[2019–09–06T19:11:47.218Z] \”GET /metrics HTTP/1.1\” 200 — \”-\” 0 0 1 0 \”-\” \”Prometheus/2.9.1\” \”f4cd2b2b-7202–9823-a8cd-7a150c6b5c4a\” \”192.168.89.3:9001\” \”127.0.0.1:9001\” inbound|80|foo-worker|hello-world.foo-namespace.svc.cluster.local — 192.168.89.3:9001 192.168.167.109:53458 -”,
“URI”: “/metrics”,
“UpstreamCluster”: “inbound|80|foo-worker|hello-world.foo-namespace.svc.cluster.local”
}

Fin

Techie. Breadth over depth. Lazy #gopher #golang. Lover of all things #kubernetes #istio #cloudnative. University of Pennsylvania alumni. Foodie by nature.