tilo/t

Watch

Fork 0

server: memory follows the open runs (about 74 MB a run, 3 GB an hour): the container is at its 64 GiB limit and anonymous memory reaches it in about eight hours #69

New issue

Open

opened 2026-11-14 03:17:11 +00:00 by xemmerling · 0 comments

xemmerling commented

2026-11-14 03:17:11 +00:00

Owner

The container (cgroup, one line a minute)

Time	Anonymous	File cache	Times at the limit so far	Stalled on memory in the 15 min before
00:23Z	24.7 GB	21.6 GB	0	0 s
00:39Z	35.1 GB	32.7 GB	166	1.6 s
01:10Z	38.7 GB	21.4 GB	482	0.8 s
01:58Z	41.2 GB	26.2 GB	982	1.1 s
02:30Z	42.4 GB	24.9 GB	1,705	1.2 s
03:01Z	43.7 GB	23.6 GB	2,803	1.8 s
03:15Z	44.7 GB	22.2 GB	3,111

The first quarter hour is the restore of every open run. After it: 9.6 GB in 2 h 36 min. It reaches the limit more often as it goes: about 150 times per quarter hour early, 430 to 670 now.

What grows (the server's own "what the server holds" line)

Time	Resident	Runs kept	Run checks	Claim waiters	Tasks	Known reads
00:37Z	33.5 GB	841	477,652	455,077	108,844	3.43 M
01:42Z	37.8 GB	909	518,078	517,197	121,903	4.19 M
02:42Z	41.3 GB	943	561,537	628,649	129,209	3.28 M
03:12Z	42.5 GB	963	584,220	660,469	135,931

The read sets are not it: known_reads fell between 01:42Z and 02:42Z while resident memory rose 3.4 GB.
Runs kept, their checks, the claims' keys, holders, waiters and listeners, and tasks all rise together. From 00:37Z to 03:12Z: 9.0 GB for 122 more runs and 106,568 more checks, about 74 MB a run or 84 KB a check.

What the open runs are (03:16Z, `t.runs` with no end)

437 CI heads, the oldest from 17:21Z on 11-12. About 30 arrive an hour since 23:00Z and about one an hour finishes. A head has about 1,250 checks.
441 bisection probe runs, some open since 11-10: class probe starts almost nothing (14 probe jobs ended in six hours, 937 waiting).
16 idle runs, 2 schedule runs, 50 people's runs.
Their waiting work lives in the server: t.jobs holds 56 rows for open runs while the server counts 58,835 jobs waiting.

Why I change nothing

A restart restores every open run: after the 00:22Z restart anonymous memory went from 24.7 to 35.1 GB in 16 minutes.
A higher limit is capacity for a symptom.
What would help is fewer open runs or less kept in memory for a check that only waits. The first is the backlog, which is a decision for the people who own the cadence and the node's shares. The second is a change to what a waiting check holds, which I have not designed.

Related: #48 (claims held by runs that never finish), #53 (the scheduler's pass over the same queue, past 5 s since 02:47Z).

03:27Z: the cluster's own measure of the server pod (kubectl top, its working set) passed 45 GiB: 45,019 MiB at 03:26:58Z, of a 64 GiB limit. No restart: the pod is the one started at 00:22:16Z with 0 container restarts, and the server answers.

A restart does not empty it (promote of `618f31ea`, 04:39Z 11-14)

Server	Age	Anonymous memory
started 00:22Z	1 min	24.7 GB
	8 min	33.9 GB
	2 h 9 min	42.6 GB
	4 h 8 min	46.9 GB
started 04:39Z	1 min	30.4 GB
	3.5 min	37.3 GB

The old server ended at 47.4 GB of anonymous memory. The new one held 37.3 GB three and a half minutes after its start: taking over the open runs brings most of it back at once.
Both servers filled the container's 64 GiB within two minutes of starting. The rest is page cache, given back on demand, which is what the limit events count (5,194 by the old server's end). Anonymous memory is the figure to watch.
Between 00:31Z and 04:30Z it grew 13 GB, about 3 GB an hour, as before.

Three starts side by side (08:00Z 11-14)

Anonymous memory in GB by minutes since the server started:

Build	5	10	30	60	90	97	120	180	240
`c2d52b34`, started 00:22Z	33.4	34.2	36.8	39.2	40.3	40.9	42.3	45.5	47.3
`618f31ea`, started 04:39Z	37.4	38.9	40.7	42.0	43.7	44.0
`67588367`, started 06:21Z	34.2	38.6	39.3	39.6	43.0	43.7

From 30 to 95 minutes it grew 3.8, 2.9 and 3.8 GB an hour.
The lookup rewrite (acae515a, in 67588367) changed neither the level nor the growth in its first 97 minutes.

`c6dca088` holds more at the same age, with the same runs (09:31Z 11-14)

Anonymous memory in GB by minutes since the server started:

Build	5	10	20	30
`c2d52b34`, started 00:22Z	33.4	34.2	35.5	36.8
`618f31ea`, started 04:39Z	37.4	38.9	40.2	40.7
`67588367`, started 06:21Z	34.2	38.6	38.9	39.3
`c6dca088`, started 08:56Z	40.8	43.1	44.0	44.3

The servers' own holdings line about thirty minutes after each start:

	`618f31ea`	`67588367`	`c6dca088`
resident_mb	38,845	37,644	42,127
committed_mb	47,815	43,630	53,775
runs	1,000	1,001	1,017
run_checks	656,324	663,230	663,056
claim_keys	595,551	562,390	589,497
claim_waiters	636,780	539,471	571,795
claim_listeners	730,738	651,391	687,993
lookup_sets	105,002	108,604	114,731
lookup_entries	27,039	45,088	53,373
tasks	173,501	178,693	185,188

c6dca088 holds about 10% more resident and 18% more committed memory at the same age. Its runs, checks, claims, waiters and listeners are within a few percent of the builds before it.
Nothing the line counts grew alike, except lookup_entries, which had already grown on 67588367. So the line does not say where the extra 3 to 4 GB sit. c6dca088 changes what a waiter keeps between reads; that state has no count in the line.
At 44.7 GB at 33 minutes and 3 to 4 GB an hour, the server reaches the level where the last one was replaced in about two hours.

One hour on c6dca088 (10:00Z): 45.7 GB anonymous, against 39.2, 42.0 and 39.6 GB at one hour for c2d52b34, 618f31ea and 67588367. From 30 to 60 minutes it grew 1.4 GB, about 2.8 GB an hour, as the builds before it did. So the extra 4 to 6 GB is a level set at the takeover, not faster growth.

The production server's memory grows by about 3 GB an hour and it follows the number of open runs, not the read sets. Its container is already at its 64 GiB limit through file cache, and anonymous memory alone reaches that limit in about eight hours at the present rate. Nothing is failing yet. Read 03:16Z 11-14 on c2d52b34 (server pod started 00:22Z). ## The container (cgroup, one line a minute) | Time | Anonymous | File cache | Times at the limit so far | Stalled on memory in the 15 min before | |---|---|---|---|---| | 00:23Z | 24.7 GB | 21.6 GB | 0 | 0 s | | 00:39Z | 35.1 GB | 32.7 GB | 166 | 1.6 s | | 01:10Z | 38.7 GB | 21.4 GB | 482 | 0.8 s | | 01:58Z | 41.2 GB | 26.2 GB | 982 | 1.1 s | | 02:30Z | 42.4 GB | 24.9 GB | 1,705 | 1.2 s | | 03:01Z | 43.7 GB | 23.6 GB | 2,803 | 1.8 s | | 03:15Z | 44.7 GB | 22.2 GB | 3,111 | | The first quarter hour is the restore of every open run. After it: 9.6 GB in 2 h 36 min. It reaches the limit more often as it goes: about 150 times per quarter hour early, 430 to 670 now. ## What grows (the server's own "what the server holds" line) | Time | Resident | Runs kept | Run checks | Claim waiters | Tasks | Known reads | |---|---|---|---|---|---|---| | 00:37Z | 33.5 GB | 841 | 477,652 | 455,077 | 108,844 | 3.43 M | | 01:42Z | 37.8 GB | 909 | 518,078 | 517,197 | 121,903 | 4.19 M | | 02:42Z | 41.3 GB | 943 | 561,537 | 628,649 | 129,209 | 3.28 M | | 03:12Z | 42.5 GB | 963 | 584,220 | 660,469 | 135,931 | | - The read sets are not it: `known_reads` fell between 01:42Z and 02:42Z while resident memory rose 3.4 GB. - Runs kept, their checks, the claims' keys, holders, waiters and listeners, and tasks all rise together. From 00:37Z to 03:12Z: 9.0 GB for 122 more runs and 106,568 more checks, about 74 MB a run or 84 KB a check. ## What the open runs are (03:16Z, `t.runs` with no end) - 437 CI heads, the oldest from 17:21Z on 11-12. About 30 arrive an hour since 23:00Z and about one an hour finishes. A head has about 1,250 checks. - 441 bisection probe runs, some open since 11-10: class `probe` starts almost nothing (14 probe jobs ended in six hours, 937 waiting). - 16 idle runs, 2 schedule runs, 50 people's runs. - Their waiting work lives in the server: `t.jobs` holds 56 rows for open runs while the server counts 58,835 jobs waiting. ## Why I change nothing - A restart restores every open run: after the 00:22Z restart anonymous memory went from 24.7 to 35.1 GB in 16 minutes. - A higher limit is capacity for a symptom. - What would help is fewer open runs or less kept in memory for a check that only waits. The first is the backlog, which is a decision for the people who own the cadence and the node's shares. The second is a change to what a waiting check holds, which I have not designed. Related: #48 (claims held by runs that never finish), #53 (the scheduler's pass over the same queue, past 5 s since 02:47Z). **03:27Z:** the cluster's own measure of the server pod (`kubectl top`, its working set) passed 45 GiB: 45,019 MiB at 03:26:58Z, of a 64 GiB limit. No restart: the pod is the one started at 00:22:16Z with 0 container restarts, and the server answers. ## A restart does not empty it (promote of 618f31ea, 04:39Z 11-14) | Server | Age | Anonymous memory | |---|---|---| | started 00:22Z | 1 min | 24.7 GB | | | 8 min | 33.9 GB | | | 2 h 9 min | 42.6 GB | | | 4 h 8 min | 46.9 GB | | started 04:39Z | 1 min | 30.4 GB | | | 3.5 min | 37.3 GB | - The old server ended at 47.4 GB of anonymous memory. The new one held 37.3 GB three and a half minutes after its start: taking over the open runs brings most of it back at once. - Both servers filled the container's 64 GiB within two minutes of starting. The rest is page cache, given back on demand, which is what the limit events count (5,194 by the old server's end). Anonymous memory is the figure to watch. - Between 00:31Z and 04:30Z it grew 13 GB, about 3 GB an hour, as before. ## Three starts side by side (08:00Z 11-14) Anonymous memory in GB by minutes since the server started: | Build | 5 | 10 | 30 | 60 | 90 | 97 | 120 | 180 | 240 | |---|---|---|---|---|---|---|---|---|---| | c2d52b34, started 00:22Z | 33.4 | 34.2 | 36.8 | 39.2 | 40.3 | 40.9 | 42.3 | 45.5 | 47.3 | | 618f31ea, started 04:39Z | 37.4 | 38.9 | 40.7 | 42.0 | 43.7 | 44.0 | | | | | 67588367, started 06:21Z | 34.2 | 38.6 | 39.3 | 39.6 | 43.0 | 43.7 | | | | - From 30 to 95 minutes it grew 3.8, 2.9 and 3.8 GB an hour. - The lookup rewrite (acae515a, in 67588367) changed neither the level nor the growth in its first 97 minutes. ## c6dca088 holds more at the same age, with the same runs (09:31Z 11-14) Anonymous memory in GB by minutes since the server started: | Build | 5 | 10 | 20 | 30 | |---|---|---|---|---| | c2d52b34, started 00:22Z | 33.4 | 34.2 | 35.5 | 36.8 | | 618f31ea, started 04:39Z | 37.4 | 38.9 | 40.2 | 40.7 | | 67588367, started 06:21Z | 34.2 | 38.6 | 38.9 | 39.3 | | c6dca088, started 08:56Z | 40.8 | 43.1 | 44.0 | 44.3 | The servers' own holdings line about thirty minutes after each start: | | 618f31ea | 67588367 | c6dca088 | |---|---|---|---| | resident_mb | 38,845 | 37,644 | 42,127 | | committed_mb | 47,815 | 43,630 | 53,775 | | runs | 1,000 | 1,001 | 1,017 | | run_checks | 656,324 | 663,230 | 663,056 | | claim_keys | 595,551 | 562,390 | 589,497 | | claim_waiters | 636,780 | 539,471 | 571,795 | | claim_listeners | 730,738 | 651,391 | 687,993 | | lookup_sets | 105,002 | 108,604 | 114,731 | | lookup_entries | 27,039 | 45,088 | 53,373 | | tasks | 173,501 | 178,693 | 185,188 | - c6dca088 holds about 10% more resident and 18% more committed memory at the same age. Its runs, checks, claims, waiters and listeners are within a few percent of the builds before it. - Nothing the line counts grew alike, except `lookup_entries`, which had already grown on 67588367. So the line does not say where the extra 3 to 4 GB sit. c6dca088 changes what a waiter keeps between reads; that state has no count in the line. - At 44.7 GB at 33 minutes and 3 to 4 GB an hour, the server reaches the level where the last one was replaced in about two hours. **One hour on c6dca088 (10:00Z):** 45.7 GB anonymous, against 39.2, 42.0 and 39.6 GB at one hour for c2d52b34, 618f31ea and 67588367. From 30 to 60 minutes it grew 1.4 GB, about 2.8 GB an hour, as the builds before it did. So the extra 4 to 6 GB is a level set at the takeover, not faster growth.

No labels

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

tilo/t#69

No description provided.

Rows
Columns