kai-server: k3s-server process sustains ~4.6 cores with no identified cause #839

Closed
opened 2026-08-15 16:52:38 +00:00 by coilyco-ops · 2 comments
Owner

Summary

The k3s-server process on kai-server holds roughly 4.6 of 28 logical cores continuously. Together with the Eco game server it accounts for essentially the entire node CPU load. I could not establish why, and I could not establish whether it is new.

Evidence

Two samples a few minutes apart, taken 2026-08-15 around 16:38-16:40Z:

pid 1950647  k3s-server  cpu 448.0%  rss 1.53 GB   (system.slice/k3s.service)
pid 1950647  k3s-server  cpu 465.5%  rss 1.54 GB
pid 3708779  EcoServer   cpu 132.2%  rss 5.10 GB   (system.slice/eco-server.service)
pid 3708779  EcoServer   cpu 131.8%  rss 5.10 GB
pid 1444254  gitea       cpu  13.7%  rss 0.57 GB   (forgejo/forgejo-6df4ddf4d5-f6zjh)

This is consistent with the node totals rather than a sampling artifact. get_cpu_info reported 17.6% of 28 cores (about 4.9 cores) and the kubelet summary reported usageNanoCores: 6277100654 (about 6.3 cores). k3s plus Eco accounts for nearly all of it.

Hypotheses ruled out

  • Not Kubernetes event churn. Only 658 events cluster-wide, dominated by the expected runner recycle 25 minutes prior.
  • Not Flux. All four Flux controllers are idle at 1-2m CPU.
  • Not workload pressure. CPU pressure stall some avg300 is 0.81% and full is 0.00%, so nothing is actually starved for CPU.

Hypothesis not tested

Kine/sqlite datastore write amplification is the obvious remaining candidate, given the node also showed a sustained write burst. I could not check it: /var/lib/rancher/k3s/server/db/state.db is outside the node-stats-mcp readable-root allowlist. Filed separately against node-stats-mcp.

Missing baseline

There is no history to compare against. kai-server does not export hostmetrics to SigNoz, so there is no record of whether 4.6 cores is a recent change or the steady state for this node. Also filed separately.

Next steps

  • Read the k3s datastore size and growth rate directly on the host
  • Check apiserver request rate and watch count from the k3s metrics endpoint
  • Establish whether this correlates with the 109-pod inventory or with a specific controller

Acceptance

Either the 4.6 cores is explained and accepted as normal for this node, or the driver is identified and reduced.

## Summary The `k3s-server` process on kai-server holds roughly 4.6 of 28 logical cores continuously. Together with the Eco game server it accounts for essentially the entire node CPU load. I could not establish why, and I could not establish whether it is new. ## Evidence Two samples a few minutes apart, taken 2026-08-15 around 16:38-16:40Z: ``` pid 1950647 k3s-server cpu 448.0% rss 1.53 GB (system.slice/k3s.service) pid 1950647 k3s-server cpu 465.5% rss 1.54 GB pid 3708779 EcoServer cpu 132.2% rss 5.10 GB (system.slice/eco-server.service) pid 3708779 EcoServer cpu 131.8% rss 5.10 GB pid 1444254 gitea cpu 13.7% rss 0.57 GB (forgejo/forgejo-6df4ddf4d5-f6zjh) ``` This is consistent with the node totals rather than a sampling artifact. `get_cpu_info` reported 17.6% of 28 cores (about 4.9 cores) and the kubelet summary reported `usageNanoCores: 6277100654` (about 6.3 cores). k3s plus Eco accounts for nearly all of it. ## Hypotheses ruled out - Not Kubernetes event churn. Only 658 events cluster-wide, dominated by the expected runner recycle 25 minutes prior. - Not Flux. All four Flux controllers are idle at 1-2m CPU. - Not workload pressure. CPU pressure stall `some` avg300 is 0.81% and `full` is 0.00%, so nothing is actually starved for CPU. ## Hypothesis not tested Kine/sqlite datastore write amplification is the obvious remaining candidate, given the node also showed a sustained write burst. I could not check it: `/var/lib/rancher/k3s/server/db/state.db` is outside the node-stats-mcp readable-root allowlist. Filed separately against node-stats-mcp. ## Missing baseline There is no history to compare against. kai-server does not export hostmetrics to SigNoz, so there is no record of whether 4.6 cores is a recent change or the steady state for this node. Also filed separately. ## Next steps - Read the k3s datastore size and growth rate directly on the host - Check apiserver request rate and watch count from the k3s metrics endpoint - Establish whether this correlates with the 109-pod inventory or with a specific controller ## Acceptance Either the 4.6 cores is explained and accepted as normal for this node, or the driver is identified and reduced.
Author
Owner

Negative result: removing the atlas crashloop changed nothing

Recording this so the next person does not re-test it.

Between the original samples and now, the forgejo-runner-deploy-atlas StatefulSet was deleted (#835, PR #843), its ~5-minute restart cycle stopped, and the Flux apps Kustomization went from Ready=False with a permanently retrying health check to Ready=True. Three wedged namespaces also finalized in the same window.

k3s-server is unchanged:

before atlas removal   cpu 448.0%   rss 1.53 GB
before atlas removal   cpu 465.5%   rss 1.54 GB
after  atlas removal   cpu 465.0%   rss 1.55 GB

EcoServer is also flat at 133.5% and 5.05 GB. gitea drifted from 13.7% down to 10.2%, consistent with the external crawl volume tapering rather than with anything that changed here.

What this rules out

  • The atlas restart cycle itself
  • The failed Flux health check and its ProgressingWithRetry loop
  • Any apiserver load from the three namespaces that had been sitting in Terminating since 2026-08-06

None of those were the driver. The 4.6 cores are something else, and they are steady rather than incident-linked.

The untested hypothesis from the original report still stands as the leading candidate: kine/sqlite datastore write amplification, blocked on the allowlist gap in coilyco-flight-deck/node-stats-mcp#23. The missing hostmetrics baseline in #841 remains the other thing that would settle whether 4.6 cores is a regression at all or simply what this node has always drawn.

## Negative result: removing the atlas crashloop changed nothing Recording this so the next person does not re-test it. Between the original samples and now, the `forgejo-runner-deploy-atlas` StatefulSet was deleted (#835, PR #843), its ~5-minute restart cycle stopped, and the Flux `apps` Kustomization went from `Ready=False` with a permanently retrying health check to `Ready=True`. Three wedged namespaces also finalized in the same window. `k3s-server` is unchanged: ``` before atlas removal cpu 448.0% rss 1.53 GB before atlas removal cpu 465.5% rss 1.54 GB after atlas removal cpu 465.0% rss 1.55 GB ``` EcoServer is also flat at 133.5% and 5.05 GB. `gitea` drifted from 13.7% down to 10.2%, consistent with the external crawl volume tapering rather than with anything that changed here. ## What this rules out - The atlas restart cycle itself - The failed Flux health check and its `ProgressingWithRetry` loop - Any apiserver load from the three namespaces that had been sitting in `Terminating` since 2026-08-06 None of those were the driver. The 4.6 cores are something else, and they are steady rather than incident-linked. The untested hypothesis from the original report still stands as the leading candidate: kine/sqlite datastore write amplification, blocked on the allowlist gap in `coilyco-flight-deck/node-stats-mcp#23`. The missing hostmetrics baseline in #841 remains the other thing that would settle whether 4.6 cores is a regression at all or simply what this node has always drawn.
Author
Owner

The premise of this issue is wrong. k3s-server is not running hot.

I measured with the wrong instrument. Correcting with the authoritative one.

process_cpu_seconds_total is a monotonic counter the kernel maintains and k3s exposes on its metrics endpoint. Sampled as a delta over a real 79 second window:

process_cpu_seconds_total: 3618444.38 -> 3618607.04
delta 162.7 cpu-seconds over 79s  =  2.06 cores

2.06 cores, not 4.6.

And the same counter answers the baseline question I claimed was unanswerable without #841. Total CPU consumed divided by process uptime:

3618607 cpu-seconds / 17.9 days uptime  =  2.34 cores lifetime average

Current draw is below this process's own long-run average. There is no anomaly and there never was one. Nothing needs explaining.

What I did wrong

I used the cpu_percent field from get_k3s_process_attribution, which is psutil-derived and sampled, and it reported 448% and 465.5% on two reads. I treated two agreeing reads as confirmation. Two agreeing reads from the same biased instrument confirm nothing, and I should have gone to the counter instead of sampling harder. The /metrics endpoint was reachable through the guarded surface the whole time.

The "hypotheses ruled out" section above is still sound as far as it goes, and the later negative result about atlas removal is still true, but all of it was chasing a number that was roughly 2x too high.

Closing this, with one real finding carried forward

The one thing worth keeping is something I found while checking: every datastore operation is averaging around 190ms, which is genuinely wrong for a local backend and is unrelated to CPU. Filed separately rather than left buried under a wrong headline.

Also noted while here, neither alarming on its own: go_goroutines is 10,055 and the apiserver is serving 100 concurrent configmap watches plus 37 on secrets.

## The premise of this issue is wrong. k3s-server is not running hot. I measured with the wrong instrument. Correcting with the authoritative one. `process_cpu_seconds_total` is a monotonic counter the kernel maintains and k3s exposes on its metrics endpoint. Sampled as a delta over a real 79 second window: ``` process_cpu_seconds_total: 3618444.38 -> 3618607.04 delta 162.7 cpu-seconds over 79s = 2.06 cores ``` **2.06 cores, not 4.6.** And the same counter answers the baseline question I claimed was unanswerable without #841. Total CPU consumed divided by process uptime: ``` 3618607 cpu-seconds / 17.9 days uptime = 2.34 cores lifetime average ``` Current draw is **below** this process's own long-run average. There is no anomaly and there never was one. Nothing needs explaining. ## What I did wrong I used the `cpu_percent` field from `get_k3s_process_attribution`, which is psutil-derived and sampled, and it reported 448% and 465.5% on two reads. I treated two agreeing reads as confirmation. Two agreeing reads from the same biased instrument confirm nothing, and I should have gone to the counter instead of sampling harder. The `/metrics` endpoint was reachable through the guarded surface the whole time. The "hypotheses ruled out" section above is still sound as far as it goes, and the later negative result about atlas removal is still true, but all of it was chasing a number that was roughly 2x too high. ## Closing this, with one real finding carried forward The one thing worth keeping is something I found while checking: every datastore operation is averaging around 190ms, which is genuinely wrong for a local backend and is unrelated to CPU. Filed separately rather than left buried under a wrong headline. Also noted while here, neither alarming on its own: `go_goroutines` is 10,055 and the apiserver is serving 100 concurrent configmap watches plus 37 on secrets.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
coilyco-flight-deck/infrastructure#839
No description provided.