d2323cb8
fix: a burst of dials past the observer table waits in the backlog
a73x 2026-09-05 19:04
Commit message
CLAUDE.md
| Old | New | ||
|---|---|---|---|
| @@ -447,6 +447,16 @@ native session panes; it is built only by the native steps and is never installe | |||
| 447 | plus 68 bytes plus the pid's digits, and neither of those directories | 447 | plus 68 bytes plus the pid's digits, and neither of those directories |
| 448 | leaves room for it in 103 (measured 2026-09-03, docs/decisions.md). | 448 | leaves room for it in 103 (measured 2026-09-03, docs/decisions.md). |
| 449 | - No socket stealing: `mux d start` refuses a path another daemon owns. | 449 | - No socket stealing: `mux d start` refuses a path another daemon owns. |
| 450 | - **A dial the observer table cannot hold waits in the kernel backlog; it | ||
| 451 | is never accepted and closed.** Every new connection lands in one of four | ||
| 452 | observer slots until its attach frame promotes it, and eight tile pumps | ||
| 453 | dial within 150 µs of each other, so the accept loop used to fill the | ||
| 454 | four with peers whose frame was still in flight and close the fifth — | ||
| 455 | one tile of an eight-tile wall lost at birth with nothing painted, one | ||
| 456 | run in four (2026-09-05). `Server.freeObserverSlot` is asked before the | ||
| 457 | accept and `pumpOnce` polls the listener only while it answers. The | ||
| 458 | harness's three-at-a-time fill rule in `test/e2e_lib.sh` was the | ||
| 459 | workaround and is now only a habit. | ||
| 450 | - **A deleted socket path is taken back within a second, and the log says | 460 | - **A deleted socket path is taken back within a second, and the log says |
| 451 | so.** A unix listener outlives its path: delete the file and the daemon | 461 | so.** A unix listener outlives its path: delete the file and the daemon |
| 452 | keeps every session on an inode nothing can reach by name (2026-09-04, a | 462 | keeps every session on an inode nothing can reach by name (2026-09-04, a |
docs/decisions.md
| Old | New | ||
|---|---|---|---|
| @@ -9295,3 +9295,48 @@ local to the box. | |||
| 9295 | - `make check` flaked once on `Pty.adopt`'s 5 s exit-code wait while a | 9295 | - `make check` flaked once on `Pty.adopt`'s 5 s exit-code wait while a |
| 9296 | sibling worktree's `make ci` was loading the box; green on the re-run, | 9296 | sibling worktree's `make ci` was loading the box; green on the re-run, |
| 9297 | and unrelated to any file this branch touched. | 9297 | and unrelated to any file this branch touched. |
| 9298 | |||
| 9299 | ## 2026-09-05 — a burst of dials past the observer table waits in the backlog | ||
| 9300 | |||
| 9301 | Found rebasing the socket-lifecycle branch onto main: `make ci` failed the | ||
| 9302 | refused-tile leg of `test/e2e_13_birth.sh` at one run in four, on a tree | ||
| 9303 | whose every other run was green, and on main's own build. The leg seeds an | ||
| 9304 | eight-tile wall on one daemon, fills the table, and births a ninth to be | ||
| 9305 | refused; the ninth was SEATED instead, on a slot one of the eight had let | ||
| 9306 | go of at birth. strace on the wall showed the eight pumps dialling within | ||
| 9307 | 150 µs of each other and one of them taking SIGPIPE on its first write 34 µs | ||
| 9308 | after its connect returned: the daemon's accept loop had run ahead of the | ||
| 9309 | attach frames, filled the four observer slots with peers whose frame was | ||
| 9310 | still in flight, and closed the fifth at accept — `conn.close(); // out of | ||
| 9311 | slots`. The pump ended that tile quietly, nothing painted, and the wall | ||
| 9312 | stood at seven tiles with a slot to spare. | ||
| 9313 | |||
| 9314 | **Decided:** `Server.freeObserverSlot` is asked BEFORE the accept, and | ||
| 9315 | `pumpOnce` polls the listener only while it answers. A fifth simultaneous | ||
| 9316 | dial waits in the kernel's listen backlog (128 deep) until a promotion or | ||
| 9317 | an idle drop frees a slot — the backlog is the queue and the observer table | ||
| 9318 | is the set of connections the daemon is reading, and accepting a connection | ||
| 9319 | it cannot read was never a service. The idle rule stands: four silent peers | ||
| 9320 | now delay the fifth by up to `observer_idle_ms` rather than close it with | ||
| 9321 | no diagnostic. The harness's "three at a time" fill rule in `test/e2e_lib.sh` | ||
| 9322 | was the workaround for this, measured 2026-08; it stays as written, since | ||
| 9323 | the arithmetic beside it is built for the batch, but it is no longer what | ||
| 9324 | keeps a fill alive. | ||
| 9325 | |||
| 9326 | **Measured** (`burst8.sh`: eight piped attaches to one fresh daemon at | ||
| 9327 | once, thirty trials, count of "connection to the daemon lost"): | ||
| 9328 | |||
| 9329 | | daemon | lost / 240 | | ||
| 9330 | |---|---| | ||
| 9331 | | this branch before the fix, Debug | 118 | | ||
| 9332 | | main `ad746c0f`, Debug | 118 | | ||
| 9333 | | main's parent's blocking dial swapped back in, Debug | 118 | | ||
| 9334 | | installed v0.0.1-17, ReleaseSafe | 18 | | ||
| 9335 | | this branch after the fix, Debug | 0 | | ||
| 9336 | |||
| 9337 | The blocking-dial row is the A/B that cleared main's new | ||
| 9338 | `open_wait.connectUnix`: the loss is the daemon's, and a release build only | ||
| 9339 | narrows the window. Pinned by the observer-burst test in | ||
| 9340 | `server_test_attach.zig`: eight connects with no frame behind them, exactly | ||
| 9341 | four held after twenty pumps, and all eight seated and served once the | ||
| 9342 | frames arrive. | ||
src/server/server.zig
| Old | New | ||
|---|---|---|---|
| @@ -995,7 +995,12 @@ pub const Server = struct { | |||
| 995 | for (&self.sessions.table, 0..) |*slot, si| { | 995 | for (&self.sessions.table, 0..) |*slot, si| { |
| 996 | fds[si] = pollIn(if (slot.*) |*s| s.pty.master else -1); | 996 | fds[si] = pollIn(if (slot.*) |*s| s.pty.master else -1); |
| 997 | } | 997 | } |
| 998 | fds[listener_idx] = pollIn(self.bound.fd); | 998 | // The listener is polled only while an observer slot is free to |
| 999 | // land the connection in. With every slot taken, a peer waits in | ||
| 1000 | // the kernel's listen backlog until a promotion or an idle drop | ||
| 1001 | // frees one; polling the listener anyway would wake this loop | ||
| 1002 | // every pass for a connection `acceptConn` could not take. | ||
| 1003 | fds[listener_idx] = pollIn(if (self.freeObserverSlot() != null) self.bound.fd else -1); | ||
| 999 | for (&self.clients, 0..) |*slot, i| { | 1004 | for (&self.clients, 0..) |*slot, i| { |
| 1000 | if (slot.*) |*c| { | 1005 | if (slot.*) |*c| { |
| 1001 | // POLLOUT only while something is owed: asking for it on an | 1006 | // POLLOUT only while something is owed: asking for it on an |
| @@ -1157,7 +1162,25 @@ pub const Server = struct { | |||
| 1157 | } | 1162 | } |
| 1158 | } | 1163 | } |
| 1159 | 1164 | ||
| 1165 | /// The observer slot the next accepted connection lands in, or null | ||
| 1166 | /// when all four are taken. `pumpOnce` asks it before polling the | ||
| 1167 | /// listener, so a burst of dials is never accepted faster than the | ||
| 1168 | /// slots drain: the fifth peer of a burst waits in the kernel backlog | ||
| 1169 | /// (128 deep) until a promotion or an idle drop frees a slot. Accepting | ||
| 1170 | /// it and closing it, which is what this loop did until 2026-09-05, | ||
| 1171 | /// lost the fifth tile of an eight-tile wall at birth with no | ||
| 1172 | /// diagnostic, because eight pumps dial within a hundred microseconds | ||
| 1173 | /// and the accept loop ran ahead of their attach frames — measured at | ||
| 1174 | /// 118 of 240 attaches lost in eight-way bursts on a Debug daemon. | ||
| 1175 | fn freeObserverSlot(self: *const Server) ?usize { | ||
| 1176 | for (self.observers, 0..) |slot, i| { | ||
| 1177 | if (slot == null) return i; | ||
| 1178 | } | ||
| 1179 | return null; | ||
| 1180 | } | ||
| 1181 | |||
| 1160 | fn acceptConn(self: *Server) void { | 1182 | fn acceptConn(self: *Server) void { |
| 1183 | const slot = self.freeObserverSlot() orelse return; | ||
| 1161 | // CLOEXEC on the accepted fd, which is what std.net.Server.accept | 1184 | // CLOEXEC on the accepted fd, which is what std.net.Server.accept |
| 1162 | // did here before: the daemon forks a shell per session and a live | 1185 | // did here before: the daemon forks a shell per session and a live |
| 1163 | // client connection leaked into one outlives every close of ours. | 1186 | // client connection leaked into one outlives every close of ours. |
| @@ -1172,13 +1195,7 @@ pub const Server = struct { | |||
| 1172 | conn.close(); | 1195 | conn.close(); |
| 1173 | return; | 1196 | return; |
| 1174 | }; | 1197 | }; |
| 1175 | for (&self.observers) |*slot| { | 1198 | self.observers[slot] = .{ .fd = conn.handle, .since_ms = monoMs() }; |
| 1176 | if (slot.* == null) { | ||
| 1177 | slot.* = .{ .fd = conn.handle, .since_ms = monoMs() }; | ||
| 1178 | return; | ||
| 1179 | } | ||
| 1180 | } | ||
| 1181 | conn.close(); // out of slots | ||
| 1182 | } | 1199 | } |
| 1183 | 1200 | ||
| 1184 | /// Once a second: does `sock_path` still name the socket we bound? A | 1201 | /// Once a second: does `sock_path` still name the socket we bound? A |
src/server/server_test_attach.zig
| Old | New | ||
|---|---|---|---|
| @@ -1613,3 +1613,58 @@ test "Server: an observer that dribbles a huge frame is dropped at the cap, not | |||
| 1613 | }); | 1613 | }); |
| 1614 | try std.testing.expect(5 + req.len < srv_mod.observer_inbound_max); | 1614 | try std.testing.expect(5 + req.len < srv_mod.observer_inbound_max); |
| 1615 | } | 1615 | } |
| 1616 | |||
| 1617 | fn seatedClients(s: *const Server) usize { | ||
| 1618 | var n: usize = 0; | ||
| 1619 | for (s.clients) |c| { | ||
| 1620 | if (c != null) n += 1; | ||
| 1621 | } | ||
| 1622 | return n; | ||
| 1623 | } | ||
| 1624 | |||
| 1625 | fn heldObservers(s: *const Server) usize { | ||
| 1626 | var n: usize = 0; | ||
| 1627 | for (s.observers) |o| { | ||
| 1628 | if (o != null) n += 1; | ||
| 1629 | } | ||
| 1630 | return n; | ||
| 1631 | } | ||
| 1632 | |||
| 1633 | fn eightSeated(s: *Server) bool { | ||
| 1634 | return seatedClients(s) == 8; | ||
| 1635 | } | ||
| 1636 | |||
| 1637 | test "Server: a burst of dials past the observer table waits in the backlog, and every one is seated" { | ||
| 1638 | const alloc = std.testing.allocator; | ||
| 1639 | var td = try h.TestDaemon.init(alloc, "burst", .{ .shell = "/bin/sh" }); | ||
| 1640 | defer td.deinit(); | ||
| 1641 | |||
| 1642 | // Eight connects with no attach frame behind any of them yet: twice the | ||
| 1643 | // observer table, and the shape of an eight-tile wall whose pumps dial | ||
| 1644 | // within a hundred microseconds of each other. The gap between the | ||
| 1645 | // connect and the frame is the race: the daemon's accept loop used to | ||
| 1646 | // run ahead of the frames, fill the four slots with silent peers and | ||
| 1647 | // close the fifth outright, which lost one tile of eight at birth with | ||
| 1648 | // nothing painted (test/e2e_13_birth.sh's refused-tile leg, flaky at | ||
| 1649 | // one run in four on 2026-09-05). | ||
| 1650 | var conns: [8]std.net.Stream = undefined; | ||
| 1651 | for (&conns) |*c| c.* = try dial.dial(td.sock_path); | ||
| 1652 | defer for (conns) |c| c.close(); | ||
| 1653 | |||
| 1654 | // Let the daemon accept what it will before any frame arrives. Exactly | ||
| 1655 | // the table's worth lands; the other four are the kernel's to hold. | ||
| 1656 | for (0..20) |_| try td.srv.pumpOnce(5); | ||
| 1657 | try std.testing.expectEqual(srv_mod.max_observers, heldObservers(&td.srv)); | ||
| 1658 | try std.testing.expectEqual(@as(usize, 0), seatedClients(&td.srv)); | ||
| 1659 | |||
| 1660 | for (conns) |c| try proto.writeFrame(c.handle, .attach, &proto.encodeAttach(80, 24, 0, 0)); | ||
| 1661 | try std.testing.expect(try h.pumpUntil(&td.srv, 5000, &td.srv, eightSeated)); | ||
| 1662 | try std.testing.expectEqual(@as(usize, 0), heldObservers(&td.srv)); | ||
| 1663 | |||
| 1664 | // Seated is not served: every one of the eight reads its snapshot, | ||
| 1665 | // the four that waited in the backlog included. | ||
| 1666 | for (0..40) |_| try td.srv.pumpOnce(5); | ||
| 1667 | for (conns) |c| { | ||
| 1668 | try std.testing.expect((try h.firstStateFrame(alloc, c.handle, 2000)) != null); | ||
| 1669 | } | ||
| 1670 | } | ||
test/e2e_lib.sh
| Old | New | ||
|---|---|---|---|
| @@ -481,12 +481,17 @@ await_out() { | |||
| 481 | # that made it, which is what lets these detach immediately. | 481 | # that made it, which is what lets these detach immediately. |
| 482 | # | 482 | # |
| 483 | # THREE at a time, and the number is `max_observers` minus one, not | 483 | # THREE at a time, and the number is `max_observers` minus one, not |
| 484 | # `max_clients` minus one: `acceptConn` parks EVERY new connection in an | 484 | # `max_clients` minus one. `acceptConn` parks every new connection in an |
| 485 | # observer slot and promotes it to a client only when its attach frame | 485 | # observer slot and promotes it to a client only when its attach frame |
| 486 | # arrives, so simultaneous dials contend for the four observer slots, and | 486 | # arrives, so simultaneous dials contend for the four observer slots. |
| 487 | # the ones with nowhere to land are closed outright. Measured at batch 7 | 487 | # Until 2026-09-05 the ones with nowhere to land were closed outright — |
| 488 | # on a 32-slot daemon: 11 of 31 fills died with "connection to the daemon lost" | 488 | # measured at batch 7 on a 32-slot daemon: 11 of 31 fills died with |
| 489 | # and the table never filled; at batch 3, 31 of 31 land. | 489 | # "connection to the daemon lost" and the table never filled; at batch 3, |
| 490 | # 31 of 31 land. The daemon now leaves a fifth dial in the kernel backlog | ||
| 491 | # instead (`Server.freeObserverSlot`), so the batch is no longer what | ||
| 492 | # keeps the fills alive; it stays because the count arithmetic below is | ||
| 493 | # written for it and a fixture that races the daemon on purpose belongs | ||
| 494 | # in a leg that says so, not in a helper every group calls. | ||
| 490 | # | 495 | # |
| 491 | # STATE is a scratch home so the fills never write a wall line the leg | 496 | # STATE is a scratch home so the fills never write a wall line the leg |
| 492 | # later counts. The last name is asked back through mux a so a fill that | 497 | # later counts. The last name is asked back through mux a so a fill that |