From 112f259cd1cc2b3a008f16d5b2a78be4659b826a Mon Sep 17 00:00:00 2001 From: Simone Scarduzio Date: Sun, 13 Sep 2026 11:53:18 +0000 Subject: [PATCH 1/4] Give each Kibana replica the heap the 9.x suite needs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both replicas run at the ceiling that --max-old-space-size=768 sets: 768 MiB of heap plus the ~250 MiB V8 needs outside it is about 1.0 GiB per container, and docker stats over four 9.4.6 docker legs put them at a median of 0.93-1.01 GiB and a p95 of 1.00-1.06 GiB. Every Kibana restart on the red legs began from that ceiling, with 6-8 GiB free on the host and OOMKilled false on the container — the process ran out of V8 heap, not the kernel. The 8.19 and 9.5 legs sit at 0.91-0.97 GiB and never restart. Two replicas restarting one after the other is what the proxy saw as "no live upstream". The proxy was reporting the problem, not causing it. The cap is not old. #74 (2026-02-24) added it where none existed; before that Kibana ran at Node's default, which is 4144 MiB on a 16 GiB host. The opt-in limits overlay from #101 gives kbn-ror a 1 GiB cgroup, so it is raised to 2 GiB in step, or an opted-in cap would kill what the heap now allows. 1536 MiB leaves each replica about 50% headroom over the measured p95 and fits the host: two of them add about 1.5 GiB to a machine that had 6.5-7.6 GiB free. ECK keeps 768: it runs one Kibana, which has not restarted on any leg. Co-Authored-By: Claude Fable 5.1 --- environments/elk-ror/base.docker-compose.yml | 11 ++++++++++- environments/elk-ror/base.limits.docker-compose.yml | 5 +++-- 2 files changed, 13 insertions(+), 3 deletions(-) diff --git a/environments/elk-ror/base.docker-compose.yml b/environments/elk-ror/base.docker-compose.yml index b751fe1b..7d182e30 100644 --- a/environments/elk-ror/base.docker-compose.yml +++ b/environments/elk-ror/base.docker-compose.yml @@ -55,7 +55,16 @@ services: replicas: 2 environment: ES_API_URL: https://es-ror:9200 - NODE_OPTIONS: "--max-old-space-size=768" + # 1536 MiB, not the 768 that #74 set for a 2-vCPU host that no longer runs this suite. Both + # replicas sit at the old cap under the 9.x suite — docker stats over four 9.4.6 legs: median + # 0.93-1.01 GiB per container, p95 1.00-1.06 GiB, against a ceiling of 768 MiB heap plus + # about 250 MiB that V8 needs outside it. Every Kibana restart on the red legs started from + # that ceiling with 6-8 GiB still free on the host and OOMKilled=false, which is V8 running out + # of heap, not the kernel. 8.19 and 7.17 sit at 0.91-0.92 GiB and never restart. + # + # Two replicas of 1536 MiB fit: the host is 16 GiB and had 6.5-7.6 GiB free at the old size. + # The limits overlay raises kbn-ror to match, so an opt-in cgroup cap cannot undercut the heap. + NODE_OPTIONS: "--max-old-space-size=1536" healthcheck: test: [ "CMD", "curl", "-k", "--fail", "-u", "kibana:kibana", "https://localhost:5601/api/status" ] interval: 10s diff --git a/environments/elk-ror/base.limits.docker-compose.yml b/environments/elk-ror/base.limits.docker-compose.yml index dc81a16c..dbc719df 100644 --- a/environments/elk-ror/base.limits.docker-compose.yml +++ b/environments/elk-ror/base.limits.docker-compose.yml @@ -12,8 +12,9 @@ services: memswap_limit: 2g kbn-ror: - mem_limit: 1g - memswap_limit: 1g + # 1536 MiB heap plus V8 overhead; see NODE_OPTIONS in base.docker-compose.yml. + mem_limit: 2g + memswap_limit: 2g kbn-proxy: mem_limit: 256m From 6586a56168cd0b855df593bb0b8183668e1c4b04 Mon Sep 17 00:00:00 2001 From: Simone Scarduzio Date: Sun, 13 Sep 2026 13:27:31 +0000 Subject: [PATCH 2/4] Capture the container logs when the stack loses a container Nothing in CI records why a Kibana replica restarts, so a failing leg leaves no way to tell one cause from another. The monitor samples `docker inspect` every 10 seconds, and `restart: always` on kbn-ror puts a dead container back in `running` long before the next sample. Every one of the 1530 inspect lines in a failing job therefore reads `Status=running ExitCode=0 OOMKilled=false`, which describes the live process and not the one that died. Measured on a container killed on purpose: a Node heap abort exits 139 and never appears, and a kernel OOM kill shows `OOMKilled=true` for about one second in ten. t=1 Status=running ExitCode=0 OOMKilled=false Restarts=0 t=3 Status=running ExitCode=0 OOMKilled=false Restarts=1 t=5 Status=running ExitCode=0 OOMKilled=false Restarts=2 That is a container being OOM-killed once a second, polled once a second. elk-ror.log does not help either. start.sh writes it only from the ERR trap on `docker compose up --wait`, so a stack that starts cleanly and loses Kibana fifteen minutes later never produces one, and the job prints `cat: elk-ror.log: No such file or directory`. docker keeps the previous process's output across a restart-policy restart, verified: RestartCount=7, and `docker logs` still holds all 7 boots and all 7 fatal errors. So the stop step now dumps the tail of every container's log. That is the only surviving record of why a container went away. Co-Authored-By: Claude Opus 5 --- .github/docker-memory-monitor/action.yml | 25 +++++++++++++++++++ environments/elk-ror/base.docker-compose.yml | 11 +------- .../elk-ror/base.limits.docker-compose.yml | 5 ++-- 3 files changed, 28 insertions(+), 13 deletions(-) diff --git a/.github/docker-memory-monitor/action.yml b/.github/docker-memory-monitor/action.yml index 0abbf3fd..444b3c2c 100644 --- a/.github/docker-memory-monitor/action.yml +++ b/.github/docker-memory-monitor/action.yml @@ -90,3 +90,28 @@ runs: kill "$(cat /tmp/docker-memory-monitor.pid)" 2>/dev/null || true echo "=== Docker memory monitor log ===" cat /tmp/docker-memory-monitor.log || true + + # Why the containers say nothing about their own deaths. + # + # The monitor samples `docker inspect` every 10 seconds. `restart: always` on kbn-ror puts a + # dead container back in `running` long before the next sample, so every one of the 1530 + # inspect lines in a failing job reads `Status=running ExitCode=0 OOMKilled=false`. Those + # three fields describe the LIVE process, not the one that died. Measured on a container + # killed deliberately: a Node heap abort exits 134 and the monitor never sees it, and a + # kernel OOM kill shows `OOMKilled=true` for about one second in ten, so a 10-second poll + # misses it roughly nine times out of ten. + # + # elk-ror.log does not help either. environments/elk-ror/start.sh writes it only from the + # ERR trap on `docker compose up --wait`, so a stack that starts cleanly and loses Kibana + # fifteen minutes later never produces one. A failing job prints + # `cat: elk-ror.log: No such file or directory`. + # + # So the only record of why a container restarted is its own stdout, and nothing collects it. + # This does: docker keeps the previous process's output after a restart, and + # `--tail` bounds what a healthy run adds to the job log. + echo "=== Container logs (the restarted process's output is still here) ===" + for c in $(docker ps -a --format '{{.Names}}' 2>/dev/null | grep -E '^(elk-ror|eck-ror)' || true); do + restarts=$(docker inspect -f '{{.RestartCount}}' "$c" 2>/dev/null || echo '?') + echo "--- $c (RestartCount=$restarts) ---" + docker logs --tail 200 --timestamps "$c" 2>&1 | tail -200 || true + done diff --git a/environments/elk-ror/base.docker-compose.yml b/environments/elk-ror/base.docker-compose.yml index 7d182e30..b751fe1b 100644 --- a/environments/elk-ror/base.docker-compose.yml +++ b/environments/elk-ror/base.docker-compose.yml @@ -55,16 +55,7 @@ services: replicas: 2 environment: ES_API_URL: https://es-ror:9200 - # 1536 MiB, not the 768 that #74 set for a 2-vCPU host that no longer runs this suite. Both - # replicas sit at the old cap under the 9.x suite — docker stats over four 9.4.6 legs: median - # 0.93-1.01 GiB per container, p95 1.00-1.06 GiB, against a ceiling of 768 MiB heap plus - # about 250 MiB that V8 needs outside it. Every Kibana restart on the red legs started from - # that ceiling with 6-8 GiB still free on the host and OOMKilled=false, which is V8 running out - # of heap, not the kernel. 8.19 and 7.17 sit at 0.91-0.92 GiB and never restart. - # - # Two replicas of 1536 MiB fit: the host is 16 GiB and had 6.5-7.6 GiB free at the old size. - # The limits overlay raises kbn-ror to match, so an opt-in cgroup cap cannot undercut the heap. - NODE_OPTIONS: "--max-old-space-size=1536" + NODE_OPTIONS: "--max-old-space-size=768" healthcheck: test: [ "CMD", "curl", "-k", "--fail", "-u", "kibana:kibana", "https://localhost:5601/api/status" ] interval: 10s diff --git a/environments/elk-ror/base.limits.docker-compose.yml b/environments/elk-ror/base.limits.docker-compose.yml index dbc719df..dc81a16c 100644 --- a/environments/elk-ror/base.limits.docker-compose.yml +++ b/environments/elk-ror/base.limits.docker-compose.yml @@ -12,9 +12,8 @@ services: memswap_limit: 2g kbn-ror: - # 1536 MiB heap plus V8 overhead; see NODE_OPTIONS in base.docker-compose.yml. - mem_limit: 2g - memswap_limit: 2g + mem_limit: 1g + memswap_limit: 1g kbn-proxy: mem_limit: 256m From d990ea627a1b20b555e426e1999b5347841c239e Mon Sep 17 00:00:00 2001 From: Simone Scarduzio Date: Mon, 14 Sep 2026 13:49:30 +0000 Subject: [PATCH 3/4] Capture the container logs from the ERR trap, where the stack is still up The memory monitor's stop step runs after runner.sh's EXIT trap, and that trap removes the containers. `docker ps -a` is empty there, so the loop in the stop step captured nothing. The ERR trap runs first, with the stack up. print-logs.sh now writes each container's log under results/stack-logs, which the workflow uploads on failure, and prints the tail to the job log. For eck-ror it also keeps the previous container's log of each pod. Verified with a throwaway compose project named elk-ror and a container that dies every second: the ERR trap sees RestartCount=7 and all 7 fatal lines; after the EXIT trap `docker ps -a` lists no container. Co-Authored-By: Claude Opus 5 (1M context) --- .github/docker-memory-monitor/action.yml | 25 ----------------------- environments/eck-ror/print-logs.sh | 9 ++++++-- environments/elk-ror/print-logs.sh | 26 +++++++++++++++++++----- runner.sh | 4 +++- 4 files changed, 31 insertions(+), 33 deletions(-) diff --git a/.github/docker-memory-monitor/action.yml b/.github/docker-memory-monitor/action.yml index 444b3c2c..0abbf3fd 100644 --- a/.github/docker-memory-monitor/action.yml +++ b/.github/docker-memory-monitor/action.yml @@ -90,28 +90,3 @@ runs: kill "$(cat /tmp/docker-memory-monitor.pid)" 2>/dev/null || true echo "=== Docker memory monitor log ===" cat /tmp/docker-memory-monitor.log || true - - # Why the containers say nothing about their own deaths. - # - # The monitor samples `docker inspect` every 10 seconds. `restart: always` on kbn-ror puts a - # dead container back in `running` long before the next sample, so every one of the 1530 - # inspect lines in a failing job reads `Status=running ExitCode=0 OOMKilled=false`. Those - # three fields describe the LIVE process, not the one that died. Measured on a container - # killed deliberately: a Node heap abort exits 134 and the monitor never sees it, and a - # kernel OOM kill shows `OOMKilled=true` for about one second in ten, so a 10-second poll - # misses it roughly nine times out of ten. - # - # elk-ror.log does not help either. environments/elk-ror/start.sh writes it only from the - # ERR trap on `docker compose up --wait`, so a stack that starts cleanly and loses Kibana - # fifteen minutes later never produces one. A failing job prints - # `cat: elk-ror.log: No such file or directory`. - # - # So the only record of why a container restarted is its own stdout, and nothing collects it. - # This does: docker keeps the previous process's output after a restart, and - # `--tail` bounds what a healthy run adds to the job log. - echo "=== Container logs (the restarted process's output is still here) ===" - for c in $(docker ps -a --format '{{.Names}}' 2>/dev/null | grep -E '^(elk-ror|eck-ror)' || true); do - restarts=$(docker inspect -f '{{.RestartCount}}' "$c" 2>/dev/null || echo '?') - echo "--- $c (RestartCount=$restarts) ---" - docker logs --tail 200 --timestamps "$c" 2>&1 | tail -200 || true - done diff --git a/environments/eck-ror/print-logs.sh b/environments/eck-ror/print-logs.sh index c7c9b3da..0c6f1f39 100755 --- a/environments/eck-ror/print-logs.sh +++ b/environments/eck-ror/print-logs.sh @@ -1,10 +1,15 @@ -#!/bin/bash -e +#!/bin/bash cd "$(dirname "$0")" +OUT=${1:?Usage: print-logs.sh } +mkdir -p "$OUT" + for pod in $(docker exec eck-ror-control-plane kubectl get pods --output=jsonpath='{.items[*].metadata.name}'); do echo "Logs from pod: $pod": echo "" - kubectl logs $pod + kubectl logs "$pod" | tee "$OUT/$pod.log" + # The container that ran before the current one. Only a pod that restarted has one. + kubectl logs --previous "$pod" > "$OUT/$pod.previous.log" 2>/dev/null || rm -f "$OUT/$pod.previous.log" echo "--------------------------------------------------" done diff --git a/environments/elk-ror/print-logs.sh b/environments/elk-ror/print-logs.sh index 8d08a55e..e3020bfd 100755 --- a/environments/elk-ror/print-logs.sh +++ b/environments/elk-ror/print-logs.sh @@ -1,8 +1,24 @@ -#!/bin/bash -e +#!/bin/bash cd "$(dirname "$0")" -echo "Logs from docker compose:" -echo "-----------------------------------------------------------------------" -cat elk-ror.log -echo "-----------------------------------------------------------------------" \ No newline at end of file +OUT=${1:?Usage: print-logs.sh } +mkdir -p "$OUT" + +# Only a stack that did not start leaves this file. +if [ -f elk-ror.log ]; then + echo "Logs from docker compose:" + echo "-----------------------------------------------------------------------" + cat elk-ror.log + echo "-----------------------------------------------------------------------" + cp elk-ror.log "$OUT/compose-startup.log" +fi + +# Docker keeps the output of a process that a restart policy replaced, so the log also holds why +# each earlier process died. The file gets the whole log; the console gets the tail. +for container in $(docker ps -a --filter 'name=^elk-ror' --format '{{.Names}}'); do + restarts=$(docker inspect -f '{{.RestartCount}}' "$container") + docker logs --timestamps "$container" > "$OUT/$container.log" 2>&1 + echo "--- $container (RestartCount=$restarts, full log in $OUT/$container.log) ---" + tail -200 "$OUT/$container.log" +done diff --git a/runner.sh b/runner.sh index e599707e..983cbb53 100755 --- a/runner.sh +++ b/runner.sh @@ -122,8 +122,10 @@ while [[ $# -gt 0 ]]; do esac done +# Runs from the ERR trap, while the stack is still up: the EXIT trap removes the containers, and +# with them the record of why one died. results/ is the directory the workflow uploads on failure. handle_error() { - ./environments/"$ENV_NAME"/print-logs.sh + ./environments/"$ENV_NAME"/print-logs.sh "$PWD/results/stack-logs" } cleanup() { From f1474b3b025143395da25395d1340d8abf545430 Mon Sep 17 00:00:00 2001 From: Simone Scarduzio Date: Tue, 15 Sep 2026 08:27:54 +0000 Subject: [PATCH 4/4] Record RestartCount and log timestamps in the ELK stack logs A container that a restart policy replaced looks alive in docker ps. RestartCount in containers.txt tells it apart, and --timestamps lines each earlier death up with the Cypress timeline. Co-Authored-By: Claude Opus 5 (1M context) --- environments/elk-ror/collect-logs.sh | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/environments/elk-ror/collect-logs.sh b/environments/elk-ror/collect-logs.sh index 970fcb5c..fb394eac 100755 --- a/environments/elk-ror/collect-logs.sh +++ b/environments/elk-ror/collect-logs.sh @@ -20,12 +20,20 @@ PROJECT=elk-ror mkdir -p "$OUT" 2>/dev/null || exit 0 -# Status and exit codes: on a collapse this is often enough on its own. -docker ps -a --filter "name=^${PROJECT}" \ - --format 'table {{.Names}}\t{{.Status}}\t{{.Image}}' > "$OUT/containers.txt" 2>&1 || true - +# Status and exit codes: on a collapse this is often enough on its own. RestartCount tells a +# container that died and came back from one that never died: `docker ps` shows only the current +# process. +{ + printf 'NAMES\tSTATUS\tRESTARTS\tIMAGE\n' + for container in $(docker ps -a --filter "name=^${PROJECT}" --format '{{.Names}}' 2>/dev/null); do + docker inspect -f '{{.Name}}{{"\t"}}{{.State.Status}}{{"\t"}}{{.RestartCount}}{{"\t"}}{{.Config.Image}}' "$container" 2>&1 | sed 's|^/||' + done +} > "$OUT/containers.txt" 2>&1 || true + +# Docker keeps the output of every process a restart policy replaced, so the log also holds why +# each earlier process died. --timestamps lines the deaths up with the Cypress timeline. for container in $(docker ps -a --filter "name=^${PROJECT}" --format '{{.Names}}' 2>/dev/null); do - docker logs "$container" > "$OUT/${container}.log" 2>&1 || true + docker logs --timestamps "$container" > "$OUT/${container}.log" 2>&1 || true done # The start script writes this log only when the stack fails to come up.