From a2f5d725a3ce090b94d4de99a5a70546d1122a54 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?St=C3=A9phane=20Tailland?= Date: Tue, 25 Aug 2026 19:05:50 +0200 Subject: [PATCH] Make the Keycloak identity events table actually render MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The panel never displayed: its query combined `line_format` with `logfmt`, and on this data that pairing is pathological. Measured on a 24h range, the stream selector with its json filter answers in 0.7s, adding line_format alone 0.3s, adding logfmt alone 0.2s — chained, 60s and a timeout. The bar panels above it survived because an aggregation streams; the log query did not. Replaced with one independent `regexp` per field, reading the key="value" pairs straight out of the JSON message without reformatting the line. 0.1s, and the raw record now stays raw since nothing rewrites it. Independent stages also fix a correctness problem the single-regexp version would have had: the field set differs per event type — LOGIN_ERROR carries `error` and `grant_type`, USER_SESSION_DELETED carries neither — so one regexp spanning them all would drop whole rows on a missing field. All four types observed on this cluster now extract correctly. Failed and successful logins widen from LOGIN_ERROR and LOGIN to the *_ERROR and CODE_TO_TOKEN families: a failed refresh or code exchange is the same signal, and TOKEN_EXCHANGE dominates this cluster's traffic. Co-Authored-By: Claude Opus 5 --- README.md | 10 ++++- k8s/grafana/dashboards/obs-audit-logs.json | 52 +++++++++++----------- 2 files changed, 35 insertions(+), 27 deletions(-) diff --git a/README.md b/README.md index 929aeb2..9916910 100644 --- a/README.md +++ b/README.md @@ -225,7 +225,15 @@ questions have nothing in common and a single view compromised on all of them. | `obs-audit-logs` | Who authenticated, what changed, who called what? | Keycloak `org.keycloak.events`, Kong http-log records | Each source keeps its own parser and they all emit the same field names, so the -frames merge into one table with consistent columns. Access logs converge on +frames merge into one table with consistent columns. + +Keycloak's identity events are read with one independent `regexp` per field +rather than `line_format` piped into `logfmt`. Two reasons, both measured: that +combination is pathological on this data — each stage answers in 0.3s alone, +chained they time out at 60s and the table never renders — and the field set +differs per event type, so a single regexp spanning them would fail whole rows +on a missing field. Independent stages leave the absent field empty and keep the +row, and the query returns in 0.1s. Access logs converge on method / path / status / client; application logs on level / message. Three things this split fixes that a single consolidated view could not: diff --git a/k8s/grafana/dashboards/obs-audit-logs.json b/k8s/grafana/dashboards/obs-audit-logs.json index 65ccbf6..31c0291 100644 --- a/k8s/grafana/dashboards/obs-audit-logs.json +++ b/k8s/grafana/dashboards/obs-audit-logs.json @@ -85,7 +85,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt [$__range])) or vector(0)", + "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` [$__range])) or vector(0)", "queryType": "instant" } ], @@ -144,7 +144,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt | type = \"LOGIN_ERROR\" [$__range])) or vector(0)", + "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | type =~ \"LOGIN_ERROR|CODE_TO_TOKEN_ERROR|REFRESH_TOKEN_ERROR\" [$__range])) or vector(0)", "queryType": "instant" } ], @@ -184,7 +184,7 @@ "graphMode": "none", "textMode": "auto" }, - "description": "A sustained non-zero value here is the signal a credential-stuffing attempt would leave." + "description": "Covers the *_ERROR event types, not just LOGIN_ERROR: a failed refresh or code exchange is the same signal. A sustained non-zero value is what a credential-stuffing attempt would leave behind." }, { "id": 4, @@ -207,7 +207,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt | type = \"LOGIN\" [$__range])) or vector(0)", + "expr": "sum(count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | type =~ \"LOGIN|CODE_TO_TOKEN\" [$__range])) or vector(0)", "queryType": "instant" } ], @@ -266,7 +266,7 @@ "type": "loki", "uid": "loki" }, - "expr": "count(sum by (clientId) (count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt [$__range]))) or vector(0)", + "expr": "count(sum by (clientId) (count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` [$__range]))) or vector(0)", "queryType": "instant" } ], @@ -325,7 +325,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum by (type) (count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt [$__auto]))", + "expr": "sum by (type) (count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` [$__auto]))", "legendFormat": "{{type}}", "queryType": "range" } @@ -366,7 +366,7 @@ "sort": "desc" } }, - "description": "LOGIN, LOGIN_ERROR, LOGOUT, REFRESH_TOKEN, CLIENT_LOGIN and the admin events Keycloak raises when a realm object changes." + "description": "LOGIN, LOGIN_ERROR, TOKEN_EXCHANGE, REFRESH_TOKEN, USER_SESSION_DELETED and the admin events Keycloak raises when a realm object changes." }, { "id": 7, @@ -389,7 +389,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum by (clientId) (count_over_time({job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt [$__auto]))", + "expr": "sum by (clientId) (count_over_time({job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"` [$__auto]))", "legendFormat": "{{clientId}}", "queryType": "range" } @@ -452,7 +452,7 @@ "type": "loki", "uid": "loki" }, - "expr": "{job=\"keycloak/keycloak\"} |~ `(?i)$search` | json logger=\"loggerName\", m=\"message\", lvl=\"level\" | logger=\"org.keycloak.events\" | line_format `{{.m}}` | logfmt", + "expr": "{job=\"keycloak/keycloak\"} |= `org.keycloak.events` |~ `(?i)$search` | json logger=\"loggerName\" | logger=\"org.keycloak.events\" | regexp `type=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `realmName=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `clientId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `userId=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `ipAddress=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `error=\\\\\"(?P[^\\\\\"]*)\\\\\"` | regexp `grant_type=\\\\\"(?P[^\\\\\"]*)\\\\\"`", "queryType": "range", "maxLines": 1000 } @@ -527,7 +527,7 @@ "properties": [ { "id": "custom.width", - "value": 180 + "value": 190 } ] }, @@ -551,7 +551,7 @@ "properties": [ { "id": "custom.width", - "value": 170 + "value": 210 } ] }, @@ -563,7 +563,7 @@ "properties": [ { "id": "custom.width", - "value": 260 + "value": 270 } ] }, @@ -575,7 +575,7 @@ "properties": [ { "id": "custom.width", - "value": 130 + "value": 120 } ] }, @@ -587,7 +587,7 @@ "properties": [ { "id": "custom.width", - "value": 220 + "value": 210 } ] }, @@ -599,7 +599,7 @@ "properties": [ { "id": "custom.width", - "value": 120 + "value": 240 } ] }, @@ -635,7 +635,7 @@ } ] }, - "description": "Keycloak writes these as key=\"value\" pairs inside its JSON message field, so the line is reformatted to the message and then read as logfmt. A userId of \"null\" means the subject was never resolved — the usual shape of a failed authentication." + "description": "Keycloak writes these as key=\"value\" pairs inside the JSON message field, read here with one regexp per field. A userId of \"null\" means the subject was never resolved — the usual shape of a failed authentication. Raw line holds the original JSON record untouched." }, { "id": 9, @@ -671,7 +671,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum(count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" [$__range])) or vector(0)", + "expr": "sum(count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" [$__range])) or vector(0)", "queryType": "instant" } ], @@ -730,7 +730,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum(count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" | status =~ \"40[13]\" [$__range])) or vector(0)", + "expr": "sum(count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" | status =~ \"40[13]\" [$__range])) or vector(0)", "queryType": "instant" } ], @@ -792,7 +792,7 @@ "type": "loki", "uid": "loki" }, - "expr": "count(sum by (client) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" [$__range]))) or vector(0)", + "expr": "count(sum by (client) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" [$__range]))) or vector(0)", "queryType": "instant" } ], @@ -851,7 +851,7 @@ "type": "loki", "uid": "loki" }, - "expr": "count(sum by (domain) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" [$__range]))) or vector(0)", + "expr": "count(sum by (domain) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" [$__range]))) or vector(0)", "queryType": "instant" } ], @@ -910,7 +910,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum by (domain) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" [$__auto]))", + "expr": "sum by (domain) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" [$__auto]))", "legendFormat": "{{domain}}", "queryType": "range" } @@ -973,7 +973,7 @@ "type": "loki", "uid": "loki" }, - "expr": "sum by (class) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\" | label_format class=`{{ printf \"%.1sxx\" .status }}` [$__auto]))", + "expr": "sum by (class) (count_over_time({job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\" | label_format class=`{{ printf \"%.1sxx\" .status }}` [$__auto]))", "legendFormat": "{{class}}", "queryType": "range" } @@ -1097,7 +1097,7 @@ "type": "loki", "uid": "loki" }, - "expr": "{job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\", authz=\"request.headers.authorization\"", + "expr": "{job=\"kong-audit\", domain=~\"${domain:regex}\"} |~ `(?i)$search` | json method=\"request.method\", path=\"request.uri\", status=\"response.status\", client=\"client_ip\", svc=\"service.name\", route=\"route.name\"", "queryType": "range", "maxLines": 1000 } @@ -1196,7 +1196,7 @@ "properties": [ { "id": "custom.width", - "value": 230 + "value": 240 } ] }, @@ -1208,7 +1208,7 @@ "properties": [ { "id": "custom.width", - "value": 80 + "value": 90 } ] }, @@ -1319,7 +1319,7 @@ } ] }, - "description": "The Raw line column holds the complete record, request and response bodies included — that is the evidentiary part, and the reason these are kept beyond what an access log needs. Note the captured Authorization header is a bearer token in clear text: acceptable for this lab, not for anything else." + "description": "Raw line holds the complete record, request and response bodies included — that is the evidentiary part, and the reason these are kept beyond what an access log needs. Note the captured Authorization header is a bearer token in clear text: acceptable for this lab, not beyond it." } ] }