diff --git a/CHANGELOG.md b/CHANGELOG.md index 3ab6f4d..25a90e7 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,16 @@ gem but are what an operator runs against their own image. ## next / unreleased +### HotCell::Server + +#### Added + +* The supervisor forks a sweeper every `sweep_interval` seconds (default 10) to delete the directories killed requests left behind. Before, only the next worker to answer on the same slot deleted them, so a slot whose every request was killed filled the scratch. + +#### Fixed + +* A worker no longer logs `slot.unswept` when the sweeper deleted the tree first. + ## v0.4.1 / 2026-09-08 ### Upgrading diff --git a/docs/DEPLOYMENT.md b/docs/DEPLOYMENT.md index 7f13d92..d935095 100644 --- a/docs/DEPLOYMENT.md +++ b/docs/DEPLOYMENT.md @@ -316,6 +316,7 @@ HotCell.limits concurrency: 4, queue_size: 8, queue_wait: 10, deadline: 30, | `queue_size` | `8` | Connections that may wait for a worker. When `running + queued` reaches `concurrency + queue_size`, the cell answers `capacity`. Use `0` to refuse instead of queueing. | | `queue_wait` | `10` | Seconds a queued connection may wait before the cell answers `capacity`. This makes a saturated cell answer with a verdict instead of holding the caller until its own timeout. | | `control_deadline` | `5` | Seconds a control connection may take to send its request. | +| `sweep_interval` | `10` | How often, in seconds, the supervisor looks for the directories that killed requests left behind. When it finds one, it forks a sweeper process to delete them. The sweeper runs under `deadline` like a worker, so the supervisor and the requests in flight never wait on the deletion. | | `max_requests_per_worker` | `1` | Requests one worker serves before the cell discards it. `1` forks per request. `:unlimited` keeps a worker for the life of the cell. See "Settings that trade one for the other". | ### Security diff --git a/docs/LOGS.md b/docs/LOGS.md index 277c212..fe1f2bd 100644 --- a/docs/LOGS.md +++ b/docs/LOGS.md @@ -41,6 +41,7 @@ Everything else is ours and sits under `hotcell.*`: | `hotcell.cause` | string | Why a worker was killed (`"deadline"`, `"memory"`, `"fsize"`, ...). | | `hotcell.signal` | string | Signal name (`"SIGKILL"`, `"SIGSEGV"`, ...). ECS has no field for signals. | | `hotcell.served` | integer | Requests a worker served before it was reaped. | +| `hotcell.swept` | integer | Discarded trees a sweeper found cleared, on `scratch.swept`: unlinked by it, or already gone when it reached them. | | `hotcell.home` | string | The scratch directory a cleanup could not clear: a request's `$HOME` from a worker, the slot directory from the supervisor. | | `hotcell.directory` | string | The cell's working directory, on `cell.boot`. | | `hotcell.operations` | array | Registered operation names, on `cell.boot`. | @@ -70,11 +71,17 @@ Everything else is ours and sits under `hotcell.*`: | `worker.unforkable` | ERROR | `hotcell.slot`, `error.type`, `error.message` | | `worker.undispatchable` | ERROR | `hotcell.slot`, `hotcell.op`, `error.type` | | `worker.unreadable_report` | ERROR | `message` | +| `sweeper.forked` | INFO | — | +| `sweeper.deadline` | WARN | `hotcell.deadline_s` | +| `sweeper.died` | WARN | `hotcell.signal`, `process.exit_code`; a sweeper that ended abnormally by anything but the deadline kill | +| `sweeper.unforkable` | ERROR | `error.type`, `error.message` | +| `sweeper.crashed` | ERROR | `error.type`, `error.message` | +| `scratch.swept` | INFO | `hotcell.swept`, `event.duration.ms` | | `control.abandoned` | WARN | `hotcell.waited_s` | | `control.unanswerable` | WARN | `error.type`, `error.message` | | `slot.uncleaned` | WARN | `hotcell.slot`, `hotcell.home`, `message` (boot sweep only) | | `slot.undiscarded` | WARN | `hotcell.slot`, `hotcell.home` | -| `slot.unswept` | WARN | `hotcell.slot`, `hotcell.home` | +| `slot.unswept` | WARN | `hotcell.slot`, `hotcell.home`; from the worker that answered on the slot or from the sweeper | | `scratch.unswept` | WARN | `hotcell.path`; `error.type` and `error.message` when the scratch itself could not be listed | ## What a worker wrote to fd 2 diff --git a/hotcell-server/lib/hot_cell/configuration.rb b/hotcell-server/lib/hot_cell/configuration.rb index 0e4e1f9..323ab3a 100644 --- a/hotcell-server/lib/hot_cell/configuration.rb +++ b/hotcell-server/lib/hot_cell/configuration.rb @@ -23,6 +23,7 @@ class Configuration queue_wait: 10, # seconds a queued connection may wait before it is answered `capacity` max_requests_per_worker: 1, # requests a worker serves before it is discarded control_deadline: 5, # seconds a control connection may take to send its request + sweep_interval: 10, # seconds between the supervisor's checks for a killed request's tree to unlink }.freeze LIMITS = { @@ -51,6 +52,7 @@ def initialize(**options) # in describe's JSON, and they may arrive as Active Support durations. @queue_wait = @queue_wait.to_f @control_deadline = @control_deadline.to_f + @sweep_interval = @sweep_interval.to_f # A nil is not "use the default" here, it is a missing number. A cell whose deadline is nil accepts # every request and then dies on the first arithmetic the supervisor does with it, so an explicit nil @@ -103,6 +105,7 @@ def verify! positive! :concurrency, integer: true positive! :queue_wait positive! :control_deadline + positive! :sweep_interval unless queue_size.is_a?(Integer) && !queue_size.negative? raise ConfigurationError, "queue_size: #{queue_size} must not be negative" diff --git a/hotcell-server/lib/hot_cell/filesystem.rb b/hotcell-server/lib/hot_cell/filesystem.rb index b20861e..c466ab8 100644 --- a/hotcell-server/lib/hot_cell/filesystem.rb +++ b/hotcell-server/lib/hot_cell/filesystem.rb @@ -18,8 +18,12 @@ module Filesystem # # `Dir.exist?` is not the guard, because it follows symlinks and answers false for a dangling one, and # an entry a tool left in a directory's place is exactly what this has to remove. + # + # A tree that is gone by the time the removal fails is the outcome this wants, however it went. Two + # sweepers can meet on one discarded tree — the worker that answered on the slot and the supervisor's + # own — and the loser's walk fails on an entry the winner unlinked first. def self.remove_tree(path) - return true unless File.exist?(path) || File.symlink?(path) + return true if gone?(path) FileUtils.remove_entry path true @@ -27,12 +31,26 @@ def self.remove_tree(path) repair_and_remove path end + # `lstat` rather than `File.exist?`, which answers false for a path it cannot stat as well as for one that + # is gone. Only ENOENT means gone; a tree behind a directory a tool made unsearchable is still there. + def self.gone?(path) + File.lstat path + false + rescue Errno::ENOENT + true + rescue SystemCallError + false + end + private_class_method :gone? + def self.repair_and_remove(path) + return true if gone?(path) + FileUtils.chmod_R 0o700, path, force: true FileUtils.remove_entry path true rescue SystemCallError - false + gone?(path) end private_class_method :repair_and_remove end diff --git a/hotcell-server/lib/hot_cell/log.rb b/hotcell-server/lib/hot_cell/log.rb index 1783b2d..ecd6ec3 100644 --- a/hotcell-server/lib/hot_cell/log.rb +++ b/hotcell-server/lib/hot_cell/log.rb @@ -35,11 +35,18 @@ class Log "worker.unforkable" => "ERROR", "worker.undispatchable" => "ERROR", "worker.unreadable_report" => "ERROR", + "sweeper.forked" => "INFO", + "sweeper.deadline" => "WARN", + "sweeper.unforkable" => "ERROR", + "sweeper.crashed" => "ERROR", + "scratch.swept" => "INFO", "control.abandoned" => "WARN", "control.unanswerable" => "WARN", "slot.uncleaned" => "WARN", "scratch.unswept" => "WARN", "slot.undiscarded" => "WARN", + "slot.unswept" => "WARN", + "sweeper.died" => "WARN", }.freeze def self.null diff --git a/hotcell-server/lib/hot_cell/server.rb b/hotcell-server/lib/hot_cell/server.rb index 041e379..2956906 100644 --- a/hotcell-server/lib/hot_cell/server.rb +++ b/hotcell-server/lib/hot_cell/server.rb @@ -15,6 +15,7 @@ require "hot_cell/counters" require "hot_cell/control" require "hot_cell/worker" +require "hot_cell/sweeper" require "hot_cell/supervisor" module HotCell diff --git a/hotcell-server/lib/hot_cell/slot.rb b/hotcell-server/lib/hot_cell/slot.rb index 479816c..9ae867f 100644 --- a/hotcell-server/lib/hot_cell/slot.rb +++ b/hotcell-server/lib/hot_cell/slot.rb @@ -95,7 +95,8 @@ def remove_home # # A rename within one filesystem is O(1) and takes the tree out of the way. A worker sweeps it later, # after it has answered and before it reports itself idle — see Worker#serve, which is the one window - # where the unlinking costs nobody's latency. + # where the unlinking costs nobody's latency. A worker killed at its deadline never reaches that window, + # so the supervisor also forks a Sweeper on a timer, which unlinks in a process of its own. # # The destination carries a random suffix rather than a counter, because the tool that filled the # directory runs as this user and can write to the slot's directory. A predictable name lets it @@ -133,12 +134,25 @@ def prepare # Unlinks whatever discard_home renamed out of the way. Partial progress is fine: a sweep killed # part-way leaves fewer entries for the next one, so this converges rather than repeating. def sweep - Dir.glob(File.join(directory, "discarded-*")).map { |path| Filesystem.remove_tree(path) }.all? + discarded.map { |path| Filesystem.remove_tree(path) }.all? rescue SystemCallError # The glob itself can fail, because the slot directory is a name a tool can replace — a symlink loop # in its place answers ELOOP here rather than for any one entry. This runs from the worker's ensure, # where a raise would replace the caller's response with a crash. false end + + # What discard_home has renamed aside and nobody has unlinked yet. + def discarded + Dir.glob(File.join(directory, "discarded-*")) + end + + # Streams the directory and stops at the first match, because the supervisor asks this in its loop and + # a tool can put as many entries beside the discarded ones as it likes; a glob would list and sort them all. + def discarded? + Dir.each_child(directory).any? { |name| name.start_with?("discarded-") } + rescue Errno::ENOENT + false + end end end diff --git a/hotcell-server/lib/hot_cell/supervisor.rb b/hotcell-server/lib/hot_cell/supervisor.rb index 76d78e8..e6e9c3e 100644 --- a/hotcell-server/lib/hot_cell/supervisor.rb +++ b/hotcell-server/lib/hot_cell/supervisor.rb @@ -22,11 +22,27 @@ module HotCell # the accept anyway, for the queue, for queued_ms, and to answer `capacity`. It also means the supervisor # knows when every worker started its current request, which is what the deadline needs. class Supervisor + # The one deadline the supervisor enforces, on a worker and on the sweeper alike: from `started_at`, + # for `deadline` seconds, killed once. `killed_for` is the one-kill latch — a killed process stays here + # until the reap, and without the latch it would be re-killed and re-logged on every pass until then. + # See `Child#overdue?` for the measurement behind that. + module Timed + def overdue?(now) + timed? && now - started_at >= deadline + end + + def expires_at + started_at + deadline if timed? + end + end + # Owns "is this worker busy" and the two transitions that change the answer, because the supervisor asking # `busy?` and the supervisor assigning the four fields `busy?` is computed from are the same fact. Spread # across the caller, a new field is one the next transition forgets to clear. Child = Struct.new(:slot, :pid, :control, :connection, :dispatched_at, :deadline, :served, :killed_for, :op, :retired_at, :buffer, :stderr, :captured, keyword_init: true) do + include Timed + def self.build(slot:, pid:, control:, deadline:, stderr: nil) new slot: slot, pid: pid, control: control, deadline: deadline, served: 0, buffer: "".b, stderr: stderr, captured: "".b @@ -87,12 +103,12 @@ def available? # SIGKILLs and 72 synchronous stdout writes for one breach. The window is longest exactly when the host # is already struggling — a worker in uninterruptible sleep, or one tearing down gigabytes of mappings — # and the loop it starves is the one enforcing every other request's deadline. - def overdue?(now) - busy? && killed_for.nil? && now - dispatched_at >= deadline + def timed? + busy? && killed_for.nil? end - def expires_at - dispatched_at + deadline if busy? && killed_for.nil? + def started_at + dispatched_at end # The retirement analogue of `overdue?`, and the only timer that can reach a worker whose idle @@ -111,6 +127,18 @@ def lingers_until(grace) end end + # The one sweeper the supervisor runs at a time. Not a `Child`: it is dispatched no request, holds no + # slot and answers nobody, so none of `busy?`, retirement or the idle report applies to it. What it + # shares with a worker is the deadline, and that is `Timed` — the same measurement, the same latch, the + # same `deadline` value from the configuration, and the same kill. + Sweep = Struct.new(:pid, :started_at, :deadline, :killed_for, keyword_init: true) do + include Timed + + def timed? + killed_for.nil? + end + end + # A path longer than this fails to bind with an error that does not say so. Darwin allows four fewer # bytes than Linux, and control.sock is the longer of the two names, so it overflows first. SUN_PATH_MAX = RUBY_PLATFORM.include?("darwin") ? 104 : 108 @@ -151,6 +179,8 @@ def initialize(directory:, workspace: nil, development: false, configuration: Ho @control_pending = [] @counters = Counters.new @stopping = false + @sweep = nil + @next_sweep_at = Clock.now + configuration.sweep_interval end def boot @@ -178,10 +208,12 @@ def run enforce_deadlines enforce_retirements + enforce_sweep_deadline expire_queue expire_control retire_idle if @stopping pump + sweep_if_due end ensure shutdown @@ -204,13 +236,16 @@ def sources end # The nearest thing that needs doing without anybody knocking: a deadline, a queued connection that - # has waited long enough to be told so, or a control client that never said what it wanted. + # has waited long enough to be told so, a control client that never said what it wanted, or the + # sweeper's next tick. def wait_for now = Clock.now nearest = [ *@children.each_value.filter_map(&:expires_at), *@children.each_value.filter_map { |child| child.lingers_until(Configuration::KILL_GRACE) }, *@queue.map { |(_, queued_at)| queued_at + configuration.queue_wait }, - *@control_pending.map { |pending| pending.accepted_at + configuration.control_deadline } ].min + *@control_pending.map { |pending| pending.accepted_at + configuration.control_deadline }, + @sweep&.expires_at, + (@next_sweep_at unless @stopping) ].compact.min return nil if nearest.nil? [ nearest - now, 0 ].max @@ -459,12 +494,12 @@ def spawn deadline: configuration.limits.deadline, stderr: stderr_reader) end - # Everything the supervisor holds and the worker must not: the listener, the signal pipe, the other - # children's control sockets, and every connection the supervisor is still holding for somebody else. # The connection this worker is about to serve arrives over SCM_RIGHTS a moment from now, so closing - # the inherited copy here costs nothing and stops it lingering for the worker's whole life. + # the inherited copy in `leave_supervisor` costs nothing and stops it lingering for the worker's whole + # life. def become_worker(supervisor_side, stderr_reader, stderr_writer) - [ "CHLD", "INT", "TERM" ].each { |signal| trap signal, "DEFAULT" } + leave_supervisor + supervisor_side.close # Its own process group, so the deadline reaches the tools this request started rather than only the # Ruby process that started them. A tool is a grandchild — the worker spawns it — and killing the @@ -487,20 +522,6 @@ def become_worker(supervisor_side, stderr_reader, stderr_writer) # reasons that section records. Landlock is the candidate that fits, tracked at basecamp/hotcell#13. Process.setpgid 0, 0 - supervisor_side.close - @signals.close - @signal_writer.close - @work.close - @control.close - - @children.each_value do |child| - child.control.close - child.connection&.close - child.stderr&.close - end - @queue.each { |(connection, _)| connection.close } - @control_pending.each { |pending| pending.connection.close } - # fd 2 becomes the pipe, and it stays non-blocking. `IO.pipe` already returns both ends O_NONBLOCK # and `reopen` is a dup2, which shares the file description — so the flag would ride along on its # own. It is set here anyway, because a decision this load-bearing should be in the code rather than @@ -518,6 +539,80 @@ def become_worker(supervisor_side, stderr_reader, stderr_writer) stderr_writer.close end + # Everything the supervisor holds and a child of its must not: the listeners, the signal pipe, the + # children's control sockets, and every connection the supervisor is still holding for somebody else. + def leave_supervisor + [ "CHLD", "INT", "TERM" ].each { |signal| trap signal, "DEFAULT" } + + @signals.close + @signal_writer.close + @work.close + @control.close + + @children.each_value do |child| + child.control.close + child.connection&.close + child.stderr&.close + end + @queue.each { |(connection, _)| connection.close } + @control_pending.each { |pending| pending.connection.close } + end + + # Ticks whether or not it forks, so a sweep that outlives an interval is left to its deadline rather + # than joined by a second one. Forking only when a slot holds a tree keeps an idle cell from paying + # for a child every interval; the glob it costs is the one `Slot#discard_home` already runs inline. + def sweep_if_due + return if @stopping || Clock.now < @next_sweep_at + + @next_sweep_at = Clock.now + configuration.sweep_interval + spawn_sweeper if @sweep.nil? && discarded_anywhere? + end + + # A glob that raises is a slot directory a tool replaced, and the sweeper is the process that reports + # that, so it is forked to find out. + def discarded_anywhere? + (0...configuration.concurrency).any? { |number| Slot.build(workspace, number).discarded? } + rescue SystemCallError + true + end + + # Held to the cell's deadline: a tree that takes longer to unlink than a request is allowed to run is + # one an input built to, and the next tick sweeps what this one left. A fork that fails is the host + # under pressure, as in `spawn`; the trees wait for the next tick. + def spawn_sweeper + pid = fork do + leave_supervisor + Sweeper.new(workspace: workspace, configuration: configuration, log: log).run + end + + log.write "sweeper.forked", pid: pid + @sweep = Sweep.new(pid: pid, started_at: Clock.now, deadline: configuration.limits.deadline) + rescue SystemCallError => error + log.write "sweeper.unforkable", error: error.class.name, message: error.message + end + + # Kill first, log second, as `enforce_deadlines` does. The sweeper spawns nothing and leads no group, + # so `kill_group` reaches it through its fallback to the bare pid. + def enforce_sweep_deadline + return unless @sweep&.overdue?(Clock.now) + + @sweep.killed_for = Codes::DEADLINE + kill_group @sweep + log.write "sweeper.deadline", pid: @sweep.pid, deadline_s: @sweep.deadline + end + + # A sweeper this supervisor killed already has its `sweeper.deadline` line. Any other abnormal end — + # the OOM killer, a sibling's signal, a crash `Sweeper#run` could not catch — would otherwise leave + # only `sweeper.forked` behind, and look exactly like a sweep that finished. + def reap_sweeper(status) + unless @sweep.killed_for || status.success? + log.write "sweeper.died", pid: @sweep.pid, signal: signal_name(status), exit_code: status.exitstatus + end + + @sweep = nil + end + + # One bounded read per pass, never a loop until the pipe is empty: this runs inside the loop that # enforces every request's deadline, and the peer is a worker that can print as fast as it likes. # @@ -810,6 +905,11 @@ def reap pid, status = Process.wait2(-1, Process::WNOHANG) break if pid.nil? + if @sweep&.pid == pid + reap_sweeper status + next + end + child = @children.each_value.find { |candidate| candidate.pid == pid } next if child.nil? @@ -1142,6 +1242,7 @@ def shutdown refuse_queue "the cell is stopping" @control_pending.each { |pending| pending.connection.close } @children.each_value { |child| child.control.close unless child.control.socket.closed? } + kill_group @sweep if @sweep @work&.close @control&.close SOCKETS.each { |name| File.unlink socket_path(name) if File.socket?(socket_path(name)) } diff --git a/hotcell-server/lib/hot_cell/sweeper.rb b/hotcell-server/lib/hot_cell/sweeper.rb new file mode 100644 index 0000000..7c68bc5 --- /dev/null +++ b/hotcell-server/lib/hot_cell/sweeper.rb @@ -0,0 +1,65 @@ +# frozen_string_literal: true + +module HotCell + # Unlinks what the supervisor renamed aside, in a process of its own. + # + # How long a recursive delete takes is chosen by the input that filled the tree, so it runs in neither + # the supervisor, whose loop enforces every deadline, nor a worker's request. A worker sweeps its own + # slot after it has answered, but a worker killed at its deadline never reaches that ensure — and a slot + # whose every request is killed stacked one tree per kill until the scratch was full. This is the sweep + # that needs no request to run: the supervisor forks it on a timer, holds it to a deadline, and never + # runs two at once. + class Sweeper + def initialize(workspace:, configuration:, log:) + @workspace = workspace + @configuration = configuration + @log = log + end + + # exit! for the reason Worker#run does: nothing inherited from the supervisor may run its teardown here. + # + # The cell's memory limit goes on first, and only that one. `FileUtils.remove_entry` lists a directory + # before it unlinks anything in it, so a tree one directory wide enough allocates in proportion to its + # width; RLIMIT_DATA makes that this process's NoMemoryError and a `sweeper.crashed` line. It is a bound + # on this process and not on the cell: the cgroup counts every worker and the tmpfs too, and can run out + # first. A sweep that dies this way makes no progress on that directory, and that is accepted here. + # + # Not `file_size`: this process writes nothing but log lines, and a log that is a regular file is past + # any worker's limit already, so the first line would have killed the sweeper with SIGXFSZ. + def run + configuration.limits.merge(file_size: nil, open_files: nil).apply + started = Clock.now + swept = slots.sum { |slot| sweep slot } + + log.write "scratch.swept", pid: Process.pid, swept: swept, duration_ms: Clock.ms_since(started) + exit! 0 + rescue Exception => error + log.write "sweeper.crashed", pid: Process.pid, error: error.class.name, message: Failure.sanitize(error.message) + exit! 1 + end + + private + attr_reader :workspace, :configuration, :log + + def slots + (0...configuration.concurrency).map { |number| Slot.build(workspace, number) } + end + + # A tree that would not go is the worker's `slot.unswept`, from this pid: the same fact, whoever + # noticed it. The glob can raise — the slot directory is a name a tool can replace — and that too is + # a slot left unswept rather than the end of the sweep. + def sweep(slot) + trees = slot.discarded + removed = trees.count { |path| Filesystem.remove_tree(path) } + report_unswept slot if removed < trees.size + removed + rescue SystemCallError + report_unswept slot + 0 + end + + def report_unswept(slot) + log.write "slot.unswept", pid: Process.pid, slot: slot.number, home: slot.directory + end + end +end diff --git a/hotcell-server/test/configuration_test.rb b/hotcell-server/test/configuration_test.rb index 0035da9..8d653d3 100644 --- a/hotcell-server/test/configuration_test.rb +++ b/hotcell-server/test/configuration_test.rb @@ -9,6 +9,14 @@ def test_a_cell_boots_with_defaults assert_equal 4, configuration.concurrency assert_equal 1, configuration.max_requests_per_worker assert_equal 60, configuration.limits.deadline + assert_equal 10, configuration.sweep_interval + end + + def test_the_sweep_interval_is_configured_directly_and_described + configuration = HotCell::Configuration.new(sweep_interval: 2.5) + + assert_equal 2.5, configuration.sweep_interval + assert_equal 2.5, configuration.to_h[:sweep_interval] end def test_scheduling_and_limits_are_declared_in_one_call @@ -61,6 +69,7 @@ def test_nonsense_scheduling_is_refused assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(concurrency: 0) } assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(queue_size: -1) } assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(queue_wait: 0) } + assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(sweep_interval: 0) } assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(max_requests_per_worker: 0) } assert_raises(HotCell::ConfigurationError) { HotCell::Configuration.new(max_requests_per_worker: :forever) } end diff --git a/hotcell-server/test/log_test.rb b/hotcell-server/test/log_test.rb index 8b4b64d..86ed9dc 100644 --- a/hotcell-server/test/log_test.rb +++ b/hotcell-server/test/log_test.rb @@ -24,6 +24,7 @@ def test_each_event_declares_its_own_level assert_equal "ERROR", written("worker.crashed", slot: 0).dig(:log, :level) assert_equal "WARN", written("worker.killed", slot: 0).dig(:log, :level) assert_equal "INFO", written("request", slot: 0).dig(:log, :level) + assert_equal "WARN", written("slot.unswept", slot: 0).dig(:log, :level) end def test_an_unknown_event_is_info_rather_than_unloggable diff --git a/hotcell-server/test/slot_test.rb b/hotcell-server/test/slot_test.rb index 9b757a4..964eb24 100644 --- a/hotcell-server/test/slot_test.rb +++ b/hotcell-server/test/slot_test.rb @@ -144,6 +144,36 @@ def test_a_cleanup_that_could_not_run_answers_false end end + # Two sweepers can meet on one tree: the worker that answered on this slot and the supervisor's own. The + # loser's walk fails on an entry the winner already unlinked, and a tree that is gone by then is the + # outcome both wanted rather than a failure to report. + def test_a_sweep_that_lost_the_tree_to_another_sweeper_answers_true + @slot.make_home + @slot.discard_home + + stub_remove_entry_to_remove_and_then_fail do + assert @slot.sweep, "a tree another sweeper removed was reported as unswept" + end + end + + # `File.exist?` answers false for a path it cannot stat as well as for one that is gone, and a tool that + # takes search permission off the slot directory produces the first. That is a tree still on the disk. + def test_a_sweep_that_cannot_reach_the_tree_does_not_report_it_gone + @slot.make_home + @slot.discard_home + File.chmod 0o600, @slot.directory + + refute @slot.sweep, "a tree behind an unsearchable directory was reported as swept" + end + + def test_a_slot_knows_whether_anything_is_discarded + @slot.make_home + + refute_predicate @slot, :discarded? + @slot.discard_home + assert_predicate @slot, :discarded? + end + def test_a_cleanup_that_ran_answers_true @slot.make_home @@ -174,6 +204,17 @@ def stub_remove_entry_to_fail FileUtils.define_singleton_method(:remove_entry, original) end + def stub_remove_entry_to_remove_and_then_fail + original = FileUtils.method(:remove_entry) + FileUtils.define_singleton_method(:remove_entry) do |path, *| + original.call path + raise Errno::ENOENT, "induced" + end + yield + ensure + FileUtils.define_singleton_method(:remove_entry, original) + end + def stub_rename_to_fail original = File.method(:rename) File.define_singleton_method(:rename) { |*| raise Errno::ENOTEMPTY, "induced" } diff --git a/hotcell-server/test/sweep_test.rb b/hotcell-server/test/sweep_test.rb new file mode 100644 index 0000000..ab548e5 --- /dev/null +++ b/hotcell-server/test/sweep_test.rb @@ -0,0 +1,98 @@ +# frozen_string_literal: true + +require "test_helper" + +# The supervisor renames a killed worker's tree aside and a worker sweeps it once it has answered — but a +# worker killed at its deadline never reaches that sweep, so a slot whose every request is killed stacked +# one tree per kill until the scratch was full. The sweeper is a child the supervisor forks on a timer to +# do that unlinking off every hot path, under a deadline of its own so a tree that will not go cannot hold +# the next sweep off forever. +class SweepTest < HotCellServerTest + # Nothing here is a double. `TestCell` forks a real supervisor; the request pins a real worker, which the + # supervisor really SIGKILLs at the deadline and renames its home aside at the reap; the sweeper is a real + # forked process unlinking a real directory on disk. The test then asks the filesystem, not the log, + # whether the tree is gone — with no second request to do the sweeping, which is what 0.4.1 relied on. + def test_a_killed_workers_tree_is_swept_with_no_request_to_do_it + TestCell.boot(deadline: 0.2, concurrency: 1, sweep_interval: 0.1) do |cell| + assert_failed "killed", cell.call("test.uninterruptible", timeout: 20), cause: "deadline" + + wait_until(what: "the discarded tree to be swept") { Dir.glob(discarded(cell)).empty? } + + swept = wait_for_event(cell, "scratch.swept") + assert_equal 1, swept.sum { |event| event[:hotcell][:swept] } + end + end + + def test_the_sweeper_does_not_fork_while_nothing_is_discarded + TestCell.boot(concurrency: 1, sweep_interval: 0.05) do |cell| + assert_ok cell.call("test.echo") + sleep 0.3 + + assert_empty cell.log_events("sweeper.forked") + end + end + + # SIGSTOP stands in for a tree whose size an input chose: a sweeper that cannot finish is killed at the + # deadline, and the next tick forks another rather than waiting on it. + def test_a_sweeper_that_does_not_finish_is_killed_at_the_deadline_and_replaced + TestCell.boot(deadline: 0.3, concurrency: 1, sweep_interval: 0.1) do |cell| + plant_large_tree cell + + forked = wait_for_event(cell, "sweeper.forked") + refute_empty forked, "no sweeper was forked for the planted tree" + Process.kill :STOP, forked.first[:process][:pid] + + killed = wait_for_event(cell, "sweeper.deadline") + assert_equal 0.3, killed.first[:hotcell][:deadline_s] + + wait_until(within: 10, what: "a later sweeper to finish the job") { Dir.glob(discarded(cell)).empty? } + assert_operator cell.log_events("sweeper.forked").size, :>=, 2, "no second sweeper was forked" + end + end + + # A sweeper the supervisor did not kill can still die by signal — the cgroup's OOM killer, or a sibling + # worker sharing its uid — and a death that left only `sweeper.forked` behind was indistinguishable from + # a sweep that finished. + def test_a_sweeper_that_dies_by_signal_is_reported_and_the_next_tick_tries_again + TestCell.boot(concurrency: 1, sweep_interval: 0.1) do |cell| + plant_large_tree cell + + forked = wait_for_event(cell, "sweeper.forked") + refute_empty forked, "no sweeper was forked for the planted tree" + Process.kill :KILL, forked.first[:process][:pid] + + died = wait_for_event(cell, "sweeper.died") + assert_equal "KILL", died.first[:hotcell][:signal] + + wait_until(within: 10, what: "a later sweeper to finish the job") { Dir.glob(discarded(cell)).empty? } + assert_operator cell.log_events("sweeper.forked").size, :>=, 2, "no second sweeper was forked" + end + end + + # The sweeper writes nothing but log lines, and a log that is a regular file grows past any `file_size` + # a cell would set for its workers. A sweeper under that limit died on its first line, and a slot whose + # report came before the others was the last one ever swept. + def test_the_workers_file_size_limit_does_not_stop_the_sweeper_logging + TestCell.boot(concurrency: 1, sweep_interval: 0.1, file_size: 1024) do |cell| + plant_small_tree cell + + refute_empty wait_for_event(cell, "scratch.swept"), "the sweeper never reported. Log:\n#{cell.log}" + end + end + + private + def discarded(cell) + File.join(cell.workspace, "0", "discarded-*") + end + + def plant_small_tree(cell) + FileUtils.mkdir_p File.join(cell.workspace, "0", "discarded-planted") + end + + def plant_large_tree(cell) + staging = File.join(cell.workspace, "0", "planting") + FileUtils.mkdir_p staging + 20_000.times { |index| File.write File.join(staging, index.to_s), "" } + File.rename staging, File.join(cell.workspace, "0", "discarded-planted") + end +end