Skip to content

fix(apps): a missing container must not crash FluxOS, a failed redeploy must not uninstall the app, and a log poll must lose nothing - #1794

Open
Cabecinha84 wants to merge 23 commits into
developmentfrom
fix/container-not-found-crash-and-spurious-uninstall
Open

fix(apps): a missing container must not crash FluxOS, a failed redeploy must not uninstall the app, and a log poll must lose nothing#1794
Cabecinha84 wants to merge 23 commits into
developmentfrom
fix/container-not-found-crash-and-spurious-uninstall

Conversation

@Cabecinha84

@Cabecinha84 Cabecinha84 commented Aug 30, 2026

Copy link
Copy Markdown
Member

Status: not ready to merge — a full harness gate has not been run. The unit suite is green (6133 passing, 18 pending, 0 failing) and lint is clean, but the log-polling internals moved substantially after harness suites 58 and 59 last ran, and this branch has never had the whole suite set run against it. That gate is the next thing to happen.

Two failures observed on a live node, three hours apart, both reached from the same line of code. Fixing them opened five more in the same paths, and one of those turned the log endpoint itself into a piece of work: it answered every poll on a 1500 ms timer, lost lines written between polls, and made docker re-read the whole log to do it.

This is the node side of a four-repo change. It is additive — a client that knows nothing about it gets the old behaviour exactly — and it must ship first. See Deployment order.


1. FluxOS restart-looped until a browser tab was closed

GET /apps/applogpolling/<component>/100 for an app whose container no longer exists killed the FluxOS process. systemd restarted it, the page polled again, and it died again — one exit per poll.

21:34:45  "OPTIONS /apps/applogpolling/rustoxide_<app>/100"  204
21:34:46  "GET     /apps/applogpolling/rustoxide_<app>/100"  304
21:34:47  fluxos.service: Main process exited, code=exited, status=1/FAILURE

dockerContainerLogsPolling rejected, and appInspector called it from inside a new Promise executor without awaiting the promise it returns — so the rejection had nothing attached to it. The route is privileged (appownerabove), but any app owner could take down every node hosting their app by leaving the log page open across a removal.

The fix is now structural rather than a guard: section 7 rewrote that function to be a plain async function that returns its lines or throws, called from a try/catch. No callback, no second reporting channel, no un-awaited promise left to go unhandled.

2. A live app was uninstalled by a soft redeploy that never removed it

Changing one environment variable on a running app removed it from the node and broadcast the removal:

19:23:41  masterSlaveApps: starting docker component:rustoxide_<app>
19:23:43  REMOVAL REASON: Soft redeploy failure - failed during soft redeploy:
          Cannot read properties of undefined (reading 'Id') (softRedeploy)
19:23:46  {"type":"fluxappremoved", ...}

The catch treated every error as proof the app had been left half-removed. The reconciler had asked to start the same component two seconds earlier, the removal path found no container, and a healthy application was lost to the race. Cleanup is now gated on having actually taken the app down.

3. The shared root: a deliberate TypeError

const myContainer = await getDockerContainerOnly(idOrName);
// Don't throw error here, let it fail with property access error
// to match test expectations
const dockerContainer = docker.getContainer(myContainer.Id);

A container that is not there is an expected outcome. It now throws Container <name> not found.

4. A component redeploy uninstalled the app, every time

Both paths passed null where the teardown expects the component's docker id, and the already-joined component_app where the callee expects the bare app name.

The joined name made the monitoring key frontend_frontend_myapp. The null took each path to a different destruction: soft threw on null.startsWith and the catch uninstalled the whole app, forced and broadcast; hard put the null into sudo umount /mnt/appdata/flux-apps/null, so the volume stayed mounted, mke2fs failed, and the failure path uninstalled both components — broadcasting nothing, so peers went on believing the instance was there.

softUninstallComposedApp is the reference for both arguments. reinstallOldApplications had the same doubled name and was also fixed — that is the automatic path, the one that runs on every on-chain component spec change with no operator involved.

Both paths now publish app:componentRedeployed{ name, component, identifier, hard }on success only.

5. The endpoint owned no response, and one exit killed the node

With the redeploy fixed, redeployComponentAPI reached a line it had never reached before and answered twice. Fixing that exposed the real defect: the response had no owner. The endpoint opened it and handed the raw res down through four layers, any of which could write and some of which closed it.

A write to a closed response does not throw where it can be caught. Node reports it a tick later as an error event on res, nothing listens, and an unheard error reaches apiServer.js:232's uncaughtException handler, whose answer to anything but a DNS error is process.exit(1).

One rule now: the handler that opened the response is the only thing that closes it, in a finally. Success, failure and refusal reach the same close.

That rule was applied to softRegisterAppLocally first and missed registerAppLocally, which is the hard path — six close sites, plus a teardown passing endResponse: true, so a failed hard redeploy ended on the teardown's "was successfuly removed" while the app was destroyed. Three more of those sites were in softRedeploy's and hardRedeploy's catches. A grep for the pattern across ZelBack/src now returns nothing, and installAppLocally and testAppInstall close their own responses.

And a redeploy that gives up on purpose now says so. When the removal fails part way, the right answer is to leave the app alone for the reconciler — but returning quietly closed the stream on a progress line and answered 200, so a redeploy that never happened read as one that did.

6. "I refused" and "I destroyed the app" were the same value

registerAppLocally answered false both for "another operation holds the node, I touched nothing" and for "I failed and have already torn the app down". The redeploy paths read it as the second.

So: a component redeploy tears the component down; the spawner starts an unrelated install inside composedDelaynothing in appSpawner consults any in-progress flag; the reinstall is refused; and the redeploy answers a five-second scheduling collision by force-uninstalling a healthy app and broadcasting it. Section 2's shape, reintroduced by the change meant to stop it reporting false success.

InstallOutcome is a frozen enum in the shape of Privilege, and its docblock says what Privilege's cannot: nothing answers these to a client, so the values are ours as well as the names.

INSTALLED  // it worked
REFUSED    // nothing touched — the app is exactly as it was
FAILED     // it got part way and tore down — the app is gone

All eleven call sites moved with the return type rather than being left to be found later: every value is truthy, so a site left on if (!outcome) reads a refusal as a success. The spawner no longer matches on error text to work out which case it is in — its own comment had been complaining about exactly that.

7. The log endpoint answered on a timer, lost lines, and re-read the whole log

Cost. follow: true never closes, so the only way out was a 1500 ms timer — every poll took 1500 ms whether one line was waiting or none. Measured: 1526, 1507, 1507 ms, each returning a single line.

Loss. It asked for the last N lines and the reader replaced its view with them, so anything beyond N between two polls was never shown. since did not help: it was a box a user typed into, it never advanced, and docker applies tail after since.

A reader is now given an opaque position and hands it back. Docker's since is inclusive and millisecond-resolved, so the line asked from always comes back — which is the proof there is no gap, and why a position must never advance past a line already held.

Three things the first version of this got wrong, all found by adversarial review and fixed here:

The log is not in timestamp order. A container writing to stdout and stderr has two writers, each stamping its line before the write is serialised — 3,304 backwards steps in 40,000 lines, measured. Counting the overlap by millisecond therefore missed already-delivered lines stamped just before it, and the tail of each page was delivered twice: 19 and 57 duplicates over two walks of a real log, 0 missing in both. count is now a place in the sequence docker returns, and ms is the newest timestamp delivered rather than the last line's. Walked end to end against a container alternating both streams: 12,000 lines, 0 duplicates, 0 missing, at two page sizes.

since alone re-reads the whole log. There is no index to seek with. 74 ms at 3.5 MB, 273 ms at 14 MB — and section 9's retention floor guarantees the log is always full, so that was the steady state for every open viewer. With tail present docker opens at the end and answers byte-for-byte the same in ~4 ms, flat. A positioned read sends tail = maxLines + 1; the extra frame says whether the whole set fitted, and only a reader more than a page behind pays for the scan, once. Steady-state poll: 14–15 ms against both a 3.5 MB and a 14 MB log.

A since filter is not a position, and all is not a page. A typed date was turned into a position, which dropped its line count and answered rolledOver — a data-loss warning — because a hand-typed timestamp does not land on a log line. And the 5000-line cap applied to all, keeping the oldest of them, so a caller asking for every line got the start of the log. Both are restored to what they were; see Backwards compatibility.

8. Finding a container listed every container on the node

getDockerContainerByIdOrName scanned listContainers({all: true}) to turn a name into an id. It has sixteen call sites — start, stop, restart, remove, inspect, exec, stats, logs.

Docker filters server-side, so one record comes back whatever the node is running. The exact name comparison stays and is load-bearing: the filter is a regex match, so web matches fluxwebsite too. Verified against a real daemon — websitelong resolves to itself, and websit is refused although the filter returns fluxwebsite for it.

9. An app's logs keep a floor of history instead of none

Every app container was created with one 20 MB log file. Docker does not trim a full log file, it discards it — so readable history swung between 20 MB and nothing. Measured: 400 lines into a 4 KB budget kept 20 lines at max-file: 1 and 107 at max-file: 4.

Four 5 MB files is the same 20 MB of disk and only the oldest quarter is dropped per rotation, so at least 15 MB is always readable.

This matters to section 7: a position can only be honoured if the line it names still exists. With one file, no position was ever safe. With four, any position within the last 15 MB is guaranteed present, and a genuinely lost one is reported as rolledOver rather than becoming a silent gap.

The setting is fixed at container creation, so it reaches an app when it is next redeployed. Nothing needs tearing down.

10. Deleted: a log endpoint no route could reach

appLogStream has never been routed, on any branch — git log -S over routes.js finds no route that ever named it. It traces to 766cff709, 2021-02-10, the ZelFlux rename, and was called by nothing for four and a half years.

It looked alive — its own privilege check, a content type, a place on the export list, a describe block — which is why two commits here carried fixes for code nothing could execute. It was also still broken one line below where those fixes landed: appInspector passed the error object to res.write, which takes only a string or Buffer.

Its only consumer, dockerContainerLogsStream, goes with it.


Testing

Unit — 6133 passing, 18 pending, 0 failing

Lint clean on every changed file.

Every behavioural fix was proved red by mutating the exact logic it names, then restoring the file byte-identical — dropping the overlap skip, suppressing the rollover flag, taking the position from the newest line instead of the last delivered, sending tail alongside a position, removing the bound from a positioned read, trusting docker's filter without the exact comparison, treating a since filter as a position, capping a caller with no position, re-adding a res.end() in the installer, making the left-alone path silent, and recording a raw-id removal.

Test doubles that were wrong, and are now faithful. This kept happening, so it is worth stating: the streaming res double accepted a write after close; removeAppLocally was stubbed to resolve without closing the response; registerAppLocally was stubbed to resolve undefined when it answers a value; twelve res doubles in appInstaller.test.js had no end; and the log fixtures were built in timestamp order, encoding the assumption they existed to check.

Two tests that could not fail. should return false if app already installed never reached the guard it named — the guard and the catch both answered false, so it passed on the catch. And a test of mine asserting the silent path reports drove a throw, which reaches the catch, which always wrote. Both re-pointed; the second proved red afterwards.

Integration

Suite 58 (58-component-redeploy-keeps-the-app.js) and suite 59 (59-app-log-polling-loses-nothing.js) both passed on a real fleet at the point they last ran, and 59 was proved red 4/4 against the pre-change code. Both predate the section 7 rework and need re-running — see the status note at the top.

Suite 59 asserts every line is seen exactly once across ten polls, that five consecutive polls each answer in under a second, and now that a since filter honours its line count and all is not truncated. Its writer alternates stdout and stderr, because a stdout-only writer cannot produce the out-of-order case.

End to end on a live node

Deployed to a real Arcane node and driven through the FluxOS frontend, with an app registered for the purpose writing a numbered line every second.

204 lines rendered, range 291–494, contiguous, 0 duplicates, 0 gaps. It appends — 180 → 192 → 204 while the first line stayed pinned at 291 — and 204 is past the 100-line limit, which the replace behaviour could never produce. The cursor was visible on the wire.

Log retention, A/B on one node, same FluxOS, the only variable being when the container was created:

container created log config
an app installed before this change 2026-08-31 max-file: 1, max-size: 20m — floor of zero
the app installed after it 2026-09-04 max-file: 4, max-size: 5m — floor of 15 MB

Backwards compatibility

A request without a cursor behaves exactly as it did before, and that is now true of all three shapes a deployed client sends:

request before now
/applogpolling/app/100 last 100 lines last 100 lines
/applogpolling/app/all every line every line
/applogpolling/app/100/<date> last 100 after that date last 100 after that date
/applogpolling/app/100?cursor=… the next batch

A client that knows about positions gets no cursor field back from an older node and falls back per node, per request — there is no version check anywhere, because the presence of the field is the capability signal. The cursor is a query parameter rather than a path segment for the same reason: the route has three optional segments and a fourth would 404 on a node that predates this.

Deployment order

  1. This PR, once the gate is green. Additive in both directions, and useful on its own — the 1500 ms fix, the container-lookup fix and the retention floor reach every existing client with no frontend change.
  2. The three viewers, in any order and independently:

The reverse order is harmless but pointless: a viewer shipped first would send a cursor every node ignores and sit in the fallback path.

Two line-ending PRs are stacked behind the viewer changes and are not part of this work: RunOnFlux/minecraft-server-website#25 and RunOnFlux/palworld-server-website#41.

Note on authorship

The first four commits are Valter Silva's, rebased onto current development with authorship intact. Sections 7 and 10 supersede parts of that work: the log-poll rewrite replaces the callback contract two of those commits established, and the deleted appLogStream is the code a third was fixing. That is not a criticism — they were correct for the code as it stood, and establishing that the endpoint was unreachable took a git log -S across every branch.

🤖 Generated with Claude Code

@MorningLightMountain713 MorningLightMountain713 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed the diff against development (4c3e1a848...f40ae6e9b). Both fixes address real failures and the crash fix works — I reproduced the polling crash on development and confirmed it does not occur on this branch. Four things to change before it lands.

1. The "left intact" message is not true in the case that produced the incident

softRemoved (advancedWorkflows.js:1262) is set after softRemoveAppLocally returns, so false means "the removal did not finish", not "the removal did not start". The catch at :1361 then logs the installation is left intact.

softRemoveAppLocally is a sequence: guards, spec lookup, decrypt, softUninstall*, cleanupAppDatabase. The uninstall step itself stops monitoring, then calls appDockerStop (errors swallowed by its .catch), then appDockerRemove (appUninstaller.js:651, not caught). The failure in the description throws at that last call — after monitoring has already been stopped.

For a composed app it is more than wording. softUninstallComposedApp (:1113) removes components one at a time. On this branch, with a two-component app whose second removal fails:

appDockerRemove -> fluxb_TestApp    removed
appDockerRemove -> fluxa_TestApp    Container fluxa_TestApp not found
removeAppLocally                    not called          <- the new gate, working
log.warn  "Soft redeploy of TestApp failed before the app was removed
           - the installation is left intact"

One component's container is gone and the journal says nothing happened. Either set the flag before the destructive step so it means what it says, or have the message state what is actually known: the redeploy failed during removal, no forced uninstall, convergence left to the reconciler.

2. softRedeployComponent has the same defect, and it fires on every call

advancedWorkflows.js:1515 passes appId as literal null:

await appUninstaller.softUninstallComponent(fullComponentName, null, componentSpec, res, stopAppMonitoring);

appDockerStop(null) is absorbed by its .catch; appDockerRemove(null) is not. It reaches getAppIdentifier(null)null.startsWith, which throws upstream of the new if (!myContainer) guard at dockerService.js:208, so this PR does not change it. On this branch, redeploying a component that does exist in the spec:

REMOVAL REASON: Soft redeploy failure - myapp being removed after component
frontend_myapp failed during soft redeploy:
Cannot read properties of null (reading 'startsWith') (softRedeployComponent)

removeAppLocally("myapp", <res>, force=true, endResponse=true, sendMessage=true)

Chain: getAppIdentifier (dockerService.js:49) ← getDockerContainerOnly (:187) ← appDockerRemove (:1303) ← softUninstallComponent (appUninstaller.js:651) ← softRedeployComponent (advancedWorkflows.js:1516).

Passing the component's real appId fixes it. hardRedeployComponent passes null the same way at :1631 but survives it, because hardUninstallComponent tolerates the failed removal and continues — so only the soft path changes behaviour, though the argument is wrong in both.

3. The polling fix belongs at the call site

The defect is at appInspector.js:175: an async function called inside a new Promise executor, its returned promise neither awaited nor caught. Reproducing that shape against a missing container on development produces the unhandled rejections; on this branch it produces none, so the fix does work. But it works by making dockerContainerLogsPolling resolve after it failed, which leaves the function's promise reporting success on failure and only covers throws inside the current try.

dockerService.dockerContainerLogsPolling(appname, parsedLineCount, since, cb).catch(reject);

at the call site keeps the promise honest and covers every path through the function.

Two related points in the same area:

  • A single docker error now reaches the callback twice. dockerService.js:469 calls callback(err) and then rejects into the outer catch, which calls callback(error) again. With the rethrow removed the callback is the only reporting channel, so the duplicate is now the visible behaviour.
  • dockerContainerLogsStream, which this PR also edits, has a second throw at dockerService.js:385 sitting inside the dockerContainer.logs callback rather than the enclosing try, so the function's own catch does not cover it. Worth folding into the same handling while the file is open.

4. Test coverage of the new branch

advancedWorkflows.test.js:3866 stubs the spec lookup to return null, so the throw is Flux App not found at advancedWorkflows.js:1226 — before any docker call is made. The failure in the description comes from appDockerRemove in the middle of the removal, and that is the case worth pinning. The other half of the new gate — a failure after the app is down still running the cleanup — is worth an assertion too; the only removeAppLocally expectation added is .called === false.

Smaller things

  • appReconciler.test.js:614, 625, 640, 661, 824 build new TypeError("Cannot read properties of undefined (reading 'Id')") under a comment describing it as the "production shape of a genuinely-missing container". After this change the shape is Container <name> not found; the fixtures should follow even though the handling is message-agnostic.
  • getDockerContainerOnly already logs Container ${idOrName} not found at dockerService.js:189, and the caller now throws the same string, so each miss is reported twice with identical text. The log line is redundant now that the condition is an error.
  • dockerTerminalHandler.js:64 and test-infra/runner/tests/53-terminal-exec-crash-safety.js:25 both document the .Id-off-undefined mechanism this PR removes. Both still behave correctly, but the comments now describe something that no longer exists.
  • The new describe at advancedWorkflows.test.js:3845 is inserted into the middle of a four-line comment, leaving // that require extensive mocking of database connections... orphaned after the block.

Stacking

No conflict with #1781, #1784 or #1791. #1784 already conflicts with the development tip in advancedWorkflows.js and five other files; merging this branch in produces the same six and no more. #1781 and #1791 merge clean both with and without it.

Cabecinha84 added a commit that referenced this pull request Aug 31, 2026
…ting a log failure must not kill the process

Addresses review feedback on #1794.

softRedeployComponent passed `null` where softUninstallComponent expects
the component's docker id. appDockerStop swallowed it; appDockerRemove
did not, and it reached getAppIdentifier and threw on `null.startsWith`
upstream of the container lookup. Every soft component redeploy therefore
failed, and the catch answered by uninstalling the whole app - forced,
and broadcast to the network. GET /apps/redeploycomponent/:app/:component
without `force` is that path. Both component redeploys also passed the
already-joined `component_app` where the callee expects the bare app name
and rebuilds the join itself, so the monitoring key became
`frontend_frontend_myapp` and the stop missed the real monitor.

dockerContainerLogsStream threw from inside dockerode's logs callback,
outside the reach of its own try. FluxOS installs no uncaughtException
handler, so that is the same process kill as the unhandled rejection
already fixed here, by a different route. It now reports through the
callback. appLogPolling attaches `.catch(reject)` to the polling call so
the executor covers every path through that function rather than only the
ones its catch reaches, and the three inner sites that reported to the
callback AND rejected now only reject - a single docker error was being
delivered to the caller twice.

softRedeploy's `softRemoved` gate is unchanged; its log line no longer
claims the installation is intact, which is not knowable when the removal
failed part way through a composed app. It now states what is known: the
redeploy failed during removal, no forced uninstall, convergence left to
the reconciler.

Tests: the softRedeploy gate is now pinned from a failure inside the
removal (the shape of the incident) instead of one before it starts, and
the other half of the gate - a failure after the app is down still runs
the cleanup - is asserted. appReconciler fixtures carry the new
`Container <name> not found` shape. The redundant `not found` log in
getDockerContainerOnly is gone; both direct callers treat absence as an
answer and log their own.

Full unit suite: 5657 passing, 5 pending, 0 failing.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014VxYEX7euB1Nhjs5mdqYWr
@Cabecinha84

Copy link
Copy Markdown
Member Author

All four addressed in 77aa571, plus a second defect at the same call site.

2. softRedeployComponent — the appId, and the app name too

Fixed in both component redeploys, and the argument was wrong twice, not once.

softUninstallComponent(appName, appId, ...) uses appName to build ${componentName}_${appName} for the monitoring key and hands it to cleanupPorts. Both call sites passed the already-joined fullComponentName, so a component redeploy of frontend_myapp stopped monitoring for frontend_frontend_myapp — a key that does not exist — and left the real monitor sampling a container that was about to be removed. softUninstallComposedApp (:1114) is the reference: bare app name, docker id of the component. Both paths now match it.

So GET /apps/redeploycomponent/:app/:component without force was a one-call app-wide forced uninstall, on every call.

3. The polling fix

.catch(reject) added at appInspector.js:189, and the return in the catch kept — the two cover different things and I would rather have both.

Duplicate callback removed: the three inner sites (if (err), mystream.on('error'), the stream-processing catch) now only reject. The rejection is awaited and lands in the function's catch, which is the single place that reports. The catch case was also reporting a rewritten message (An error occurred while processing the log stream) while rejecting with the original; the caller now gets the original.

dockerContainerLogsStream:385 — folded in, and it is worse than a stale comment. That throw is inside dockerode's callback, so the enclosing try has long returned when it fires. There is no uncaughtException handler anywhere in the repo (nor unhandledRejection — which is why the polling crash was fatal in the first place), so it is the same process kill by a different route. It reports through the callback now.

1. The message

Gate unchanged, wording is now what is actually known:

Soft redeploy of <app> failed during removal: <error>. No forced uninstall -
the app is not known to be down, and convergence is left to the reconciler.

I kept the flag where it is rather than moving it before the destructive step. Setting it earlier would restore the original incident: the failure there came from inside the removal, racing the reconciler, and that is exactly the case that must not uninstall. The comment on the declaration now says outright that false means "did not finish", not "did not start".

4. Tests

Three now, replacing the one:

  • failure part way through the removal — a v3 spec so the removal takes the simple path, softUninstallApplication rejecting with Container fluxTestApp not found. Asserts the stub was actually called, so it cannot silently regress to failing early again. This is the incident's shape.
  • failure before the removal starts — the previous test, kept as the other end of the range.
  • failure after the app is downcheckAppRequirements rejecting once the removal has completed; asserts removeAppLocally IS called, with ('TestApp', null, true, true, true). That was the untested half of the gate.

Smaller things

  • appReconciler.test.js fixtures now throw Container www_App not found, with the comment corrected.
  • The redundant log.error in getDockerContainerOnly is gone. Both direct callers (appInspector.js:606, appReconciler.js:459) treat a miss as an answer to a question they asked and log their own line, so it was noise on a healthy node; getDockerContainerByIdOrName, whose contract is that the container exists, still throws that text.
  • dockerTerminalHandler.js:64 and test-infra/.../53-terminal-exec-crash-safety.js:25 comments updated to the new mechanism.
  • Orphaned comment at advancedWorkflows.test.js reassembled — the new describe now sits after it.

Full unit suite: 5657 passing, 5 pending, 0 failing. eslint clean on every file touched.

@codecov

codecov Bot commented Aug 31, 2026

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 81.15183% with 36 lines in your changes missing coverage. Please review.
✅ Project coverage is 68.69%. Comparing base (cba4798) to head (12e382d).
⚠️ Report is 136 commits behind head on development.

Files with missing lines Patch % Lines
...ack/src/services/appLifecycle/advancedWorkflows.js 68.35% 25 Missing ⚠️
ZelBack/src/services/appLifecycle/appInstaller.js 80.95% 4 Missing ⚠️
ZelBack/src/services/dockerService.js 93.65% 4 Missing ⚠️
ZelBack/src/services/appManagement/appInspector.js 40.00% 3 Missing ⚠️
Additional details and impacted files
@@               Coverage Diff               @@
##           development    #1794      +/-   ##
===============================================
+ Coverage        67.77%   68.69%   +0.91%     
===============================================
  Files              188      190       +2     
  Lines            35087    35133      +46     
===============================================
+ Hits             23780    24133     +353     
+ Misses           11307    11000     -307     

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

@Cabecinha84

Copy link
Copy Markdown
Member Author

Follow-up in eee2139: the logStream.on('error') handler I mentioned in passing turned out to be half of a real leak, so I took the whole polling path rather than just the duplicate report.

follow: true makes dockerd hold a connection open for the life of the container. The 1500ms window ended the local PassThrough and left the source streaming, so the only path that resolved the awaited promise — mystream.on('end') — could not fire on a live container. The function never returned and never released the connection. Once per poll, on an endpoint a browser hits on a timer, which is the same browser tab that produced the crash in the first place.

Verified rather than reasoned: the new test times out at 10s against the previous code and completes in ~1.5s here.

  1) completes the poll and reports the end exactly once:
     Error: Timeout of 10000ms exceeded.        <- development
      ✔ completes the poll and reports the end exactly once (1518ms)   <- here

The logStream.on('error') handler was the other half: it reported through the callback without settling the promise, so an error on that stream produced the same permanent hang plus the duplicate report.

What changed:

  • Every terminal condition settles. end is the success — it fires after the last chunk is read, so every line has reached the callback by then. close is the backstop, because a stream that errored may never emit end and an unsettled promise here is a leaked connection. Errors from either stream reject, unless the window is deliberately closing.
  • The window destroys the source before ending the sink. demuxStream writes into logStream, and a write landing after end() surfaces as ERR_STREAM_WRITE_AFTER_END — a completed poll reported as a failure.
  • A finally destroys the follow stream on every exit.
  • Stream ended moved out of the stream handler to after the await, so it is reported once and only on success. From inside the handler it could follow an error the caller had already been handed, telling it the poll had finished cleanly.

Description updated with sections 4 and 5. Full unit suite: 5658 passing, 5 pending, 0 failing.

@Cabecinha84

Copy link
Copy Markdown
Member Author

@MorningLightMountain713 ready for another look when you have time.

All four points addressed in 77aa571, plus the polling path taken properly in eee2139 after your note on dockerContainerLogsStream led somewhere worse than a stale comment.

Two things worth your eye in particular, since they go beyond what you flagged:

  1. softRedeployComponent had a second wrong argument next to the null appId — both component redeploys passed the already-joined component_app where the callee expects the bare app name and rebuilds the join itself, so the monitoring key became frontend_frontend_myapp.
  2. dockerContainerLogsPolling never released the docker connection it opened. The logStream.on('error') handler you pointed at was half of it; the other half is that on a live container the awaited promise had no reachable path to settle at all. Confirmed against development rather than argued: the new test times out at 10s there, completes in ~1.5s here.

Full unit suite: 5658 passing, 5 pending, 0 failing.

Cabecinha84 and others added 12 commits September 3, 2026 14:53
… reporting it must not kill the process

getDockerContainerByIdOrName deliberately dereferenced undefined when the
container was not there, on the grounds that a test asserted the resulting
TypeError. Callers were left with `Cannot read properties of undefined
(reading 'Id')` - a message about the accident rather than the condition -
and the reconciler had to pattern-match on it to recognise a vanished
container. It now throws `Container <name> not found`.

dockerContainerLogsPolling then compounded that: its catch delivered the
failure through the callback and rethrew it as well. Every caller invokes it
from inside a `new Promise` executor without awaiting the returned promise,
so the second path was an unhandled rejection, and Node takes the process
down for those. A browser left on an app's log page after the container went
away was enough to restart-loop FluxOS indefinitely - observed on a live
node, one exit per poll, until the tab was closed.

dockerContainerLogsStream kept its own copy of the container lookup; it now
uses the same helper, so "not found" is defined in one place.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WNpKm39hh6UCcCZaqXA1ox
…all it

softRedeploy treated every error as proof that the app was left broken, and
its catch called removeAppLocally with force and sendMessage set - uninstalling
the application and broadcasting the removal to the network.

That is right only once the app is actually down. Until then the existing
installation is whole, and a transient failure - a concurrent reconcile racing
the removal, a docker call finding no container - costs a running application.
Seen in production: a soft redeploy of a live app failed two seconds after the
masterSlave reconciler asked to start the same component, and the app was
uninstalled from the node and the removal announced.

The cleanup is now gated on having reached that point. If the redeploy fails
before the app comes down, it says so and leaves the installation alone; the
reconciler converges whatever it finds.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01WNpKm39hh6UCcCZaqXA1ox
…ting a log failure must not kill the process

Addresses review feedback on #1794.

softRedeployComponent passed `null` where softUninstallComponent expects
the component's docker id. appDockerStop swallowed it; appDockerRemove
did not, and it reached getAppIdentifier and threw on `null.startsWith`
upstream of the container lookup. Every soft component redeploy therefore
failed, and the catch answered by uninstalling the whole app - forced,
and broadcast to the network. GET /apps/redeploycomponent/:app/:component
without `force` is that path. Both component redeploys also passed the
already-joined `component_app` where the callee expects the bare app name
and rebuilds the join itself, so the monitoring key became
`frontend_frontend_myapp` and the stop missed the real monitor.

dockerContainerLogsStream threw from inside dockerode's logs callback,
outside the reach of its own try. FluxOS installs no uncaughtException
handler, so that is the same process kill as the unhandled rejection
already fixed here, by a different route. It now reports through the
callback. appLogPolling attaches `.catch(reject)` to the polling call so
the executor covers every path through that function rather than only the
ones its catch reaches, and the three inner sites that reported to the
callback AND rejected now only reject - a single docker error was being
delivered to the caller twice.

softRedeploy's `softRemoved` gate is unchanged; its log line no longer
claims the installation is intact, which is not knowable when the removal
failed part way through a composed app. It now states what is known: the
redeploy failed during removal, no forced uninstall, convergence left to
the reconciler.

Tests: the softRedeploy gate is now pinned from a failure inside the
removal (the shape of the incident) instead of one before it starts, and
the other half of the gate - a failure after the app is down still runs
the cleanup - is asserted. appReconciler fixtures carry the new
`Container <name> not found` shape. The redundant `not found` log in
getDockerContainerOnly is gone; both direct callers treat absence as an
answer and log their own.

Full unit suite: 5657 passing, 5 pending, 0 failing.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014VxYEX7euB1Nhjs5mdqYWr
… it opened

`follow: true` opens a connection dockerd holds for the life of the
container. The 1500ms window ended the local PassThrough and left the
source streaming, so the only path that resolved the awaited promise -
`mystream.on('end')` - could never fire on a live container. The function
never returned and the connection was never released, once per poll, on an
endpoint a browser hits on a timer. Verified against the previous code: the
new test times out at 10s there and completes in ~1.5s here.

The log stream's own `error` handler was the other half of it. It reported
through the callback without settling the promise, so an error on that
stream produced the same permanent hang plus a duplicate report.

Every terminal condition now settles: `end` on success, `close` as the
backstop for a stream that errored and will never emit `end`, and errors
from either stream reject unless the window is deliberately closing. The
window tears the source down before ending the sink, so a demuxStream write
cannot land after `end()` and turn a completed poll into
ERR_STREAM_WRITE_AFTER_END. A `finally` destroys the follow stream on every
exit.

`Stream ended` moved out of the stream handler to after the await, so it is
reported once and only on success - it could previously follow an error the
caller had already been given, telling it the poll finished cleanly.

Full unit suite: 5658 passing, 5 pending, 0 failing.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_014VxYEX7euB1Nhjs5mdqYWr
…on neither

dockerContainerLogsPolling swallowed its own throw whenever a callback was
passed, so the promise it returns resolved after the poll had failed. The
callback carried the error and every awaiting caller read a completed poll -
including the `.catch` at the polling endpoint, which could never fire.

The error now reaches the callback and rejects, so neither channel can read a
failure as a success. Every call site is obliged to handle the rejection:
FluxOS installs no `unhandledRejection` handler, so one with nothing attached
exits the process, and this endpoint is polled by a browser on a timer.

The test asserted the swallow ("without rejecting"), so it now asserts the
contract instead: the same error on both channels, and no resolution.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ring

`container_vanished` is the heaviest tampering signal the node emits - severity
3 against a DOS threshold of 10 - and it asserts one thing: a container went
away and FluxOS did not take it. Nothing recorded who removed a container, so
an absence FluxOS caused itself scored the same as host-side interference.

A teardown that fails part way is exactly that shape: one component's container
gone, the app's row intact, the app still reconciled. Four such app-hours on a
non-Arcane node whose txhash is on the curated blocklist cross the threshold,
and the DOS message names a tamper score with no way back to the redeploy that
caused it.

globalState.fluxRemovedContainers records authorship: written by dockerService's
removal funnels once the container is actually gone, dropped by its creation
funnel, and dropped for a whole app when the app's local row goes - nothing
reconciles an app with no row, so no entry there has a reader. Only the
full-uninstall path clears; softRemoveAppLocally deletes the row too, but as one
step of a redeploy whose containers are coming back, and its records are what
the gate reads. In-memory deliberately: across a restart the node cannot tell
its own removal from anyone else's, and an entry that survived would suppress a
real signal.

recreateMissing recreates either way. Only the accusation is withheld.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…he far side of the soft-redeploy gate is marked as current behaviour

softUninstallComponent and hardUninstallComponent take the BARE app name - they
join it with the component's own name for the monitoring key - and the
component's docker id. Both redeploy paths passing the joined name and a null id
is what made every /apps/redeploycomponent call force-uninstall the whole app
and broadcast it. Nothing covered it: the endpoint has no harness suite, so
these arguments are only ever checked here.

The gate's far side - a failure after the app is already down still
force-uninstalls it - is the 2026-08-04 sequence, and closing it means releasing
to the reconciler instead (SPEC_CHANGE_CONTINUITY.md §1, §9). The test now says
it pins current behaviour and is expected to go red when that lands, so the
change reads as deliberate rather than as a regression.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
… itself on the bus

/apps/redeploycomponent had no harness coverage — `grep -rn redeploycomponent
test-infra/` found nothing — and it did not work at all: both redeploy paths
handed the component teardown a null docker id, and on the soft path the throw
was answered by force-uninstalling the whole app and broadcasting the removal.
Every call.

Suite 58 drives the endpoint against a real two-component app and asserts the
three things a unit test cannot: the subject's container is a DIFFERENT container
afterwards (the only evidence separating a redeploy from a restart), the
sibling's is the same one throughout (the only thing separating "replaced one
component" from "rebuilt the app"), and neither the node nor a watching peer was
told the app had been removed.

app:componentRedeployed is what makes any of it observable. app:installed and
app:removed both speak for a whole app, so neither fires on this path and
neither could - it leaves the app installed throughout, which is the point of
it. Nothing observing a node could tell a component redeploy from never having
been asked, which is how a hardcoded null survived in a live route.

Three harness helpers alongside it: a client call for the endpoint (it streams
progress and appends a final status, so the body is concatenated JSON objects
and has to be read as text, exactly as installapplocally is), getAppContainerId
(a docker id is the only field that changes when a container is replaced - name,
status and image are identical either way), and the usual one-line wait wrapper.

The tampering suppression is NOT covered here and the header says so: the shape
it protects is a teardown that fails part way, the harness cannot make a docker
call fail (DOCKER_FAULT_INJECTION.md, "designed, not built"), and a successful
redeploy records the removal and clears it moments later. Asserting "no
tampering event" over this path would pass with the suppression removed. What is
covered is the regression that change could cause: an absence FluxOS did not
create must still be reported.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
… once

The endpoint streams its progress, so the body starts on the first res.write
and the status line is gone from that moment. It then answered a second time
with res.json, which goes through setHeader and threw ERR_HTTP_HEADERS_SENT
into the catch, whose own res.json threw the same way - and that second throw
escaped the handler, destroying the connection instead of answering it.

The first fleet run of harness suite 58 saw exactly that: the component was
replaced correctly, app:componentRedeployed was published, the request logged
200, and the caller still got `TypeError: terminated`. The path is new - until
the component teardown took a real docker id the redeploy threw before it ever
streamed, so the trailing res.json was reached with the headers still unsent.

The whole-app redeployAPI beside it already ends this way: the stream is the
response. An error that arrives once the body has started now goes into the
stream and closes it, the shape fileSystemManager already uses.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The response is the progress stream, one envelope per step, so an error
anywhere in it is not a refusal. The teardown reports a tolerated one on every
run of this suite: both components share a repotag, so removing the subject's
image is refused with `409 conflict - container ... is using its referenced
image` while the sibling still holds it. FluxOS records that and carries on,
which is what it should do - the image is still in use.

The last envelope is what says whether the request was answered or refused: an
auth refusal is the whole body, and a mid-stream failure is what the stream
closes on.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The reconciler stands down for the whole redeploy on
globalState.isOperationInProgress(), so it never sees the container absent and
records nothing either way. "leaves no tampering event behind" therefore passed
with the suppression it appeared to cover deleted, and reads as proof of it.

The suppression is unit-proved (appReconciler.test.js, 'recreates a container
FluxOS removed itself without calling it tampering') and cannot be harness-proved
until docker fault injection exists. The header already says so.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…hat component

force=true unmounts the component's volume, wipes its app data and rm -rf's the
volume file before reinstalling. The sibling's marker is what separates wiping
one component from wiping the app: a teardown that took the app's whole volume
tree passes every container-level assertion while destroying the other
component's data.

On `development` the null docker id reaches the unmount as a literal path
segment, so `umount /mnt/appdata/flux-apps/null` fails and the volume stays
mounted. The reinstall's mke2fs then fails on the volume still in use, and the
installation-failure path uninstalls the whole app locally - both components,
without broadcasting. Asking to rebuild one component destroys the app on that
node.

Proved red against that form on a 10-node fleet: the subject is left with no
container at all.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@MorningLightMountain713
MorningLightMountain713 force-pushed the fix/container-not-found-crash-and-spurious-uninstall branch from eee2139 to fdb226d Compare September 3, 2026 19:42
…at closes it

A component redeploy that failed after the stream had started took the node
down. The teardown in the redeploy's own catch was called with endResponse
true, so appUninstaller closed the response; control then unwound to
redeployComponentAPI's catch, which wrote the error envelope into it. A write
to a closed response does not throw where it can be caught - node reports it a
tick later as an `error` event on res, nothing listens for one, and an unheard
`error` reaches apiServer's uncaughtException handler, whose answer to anything
but a DNS error is process.exit(1). Reproduced on the real middleware stack:
it fires whenever the client does not accept gzip, because compression's
wrapper absorbs the write when it does.

The same deletion left four paths with no answer at all. The guards that refuse
a redeploy while another operation holds the node write their warning and
return, and nothing below them closed the response - so the caller waited out
server.requestTimeout, two hours.

Both are the same missing rule: the response had no owner. Four layers could
write to it and any of them could close it, and the layer that opened it could
not tell. It is now closed in one place, in a finally, by the handler that
opened it - success, failure, and refusal all reach the same close. The
teardowns pass endResponse false, softRegisterAppLocally writes its outcome
without closing, and redeployAPI gets the same treatment: it has always had the
same shape, and only escaped the exit because res.json throws synchronously.

The restore-skip branch of redeployAPI answered nothing at all, which the new
close would have turned into an empty 200 - it says what happened instead.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…lled

softRegisterAppLocally does not throw when an install fails. Its catch writes
the error, fires removeAppLocally un-awaited, and returns; it also has four
guard paths that write a refusal and return without installing anything.
registerAppLocally already answers false in the same situation. Neither return
value was read.

So both component redeploy paths logged "softly redeployed" and published
app:componentRedeployed off the absence of a throw - including on the path
where the app had just been force-uninstalled underneath them. That event is
the ONLY report that a single component was replaced, so nothing else on the
node contradicted it, and the failure it was added to make visible is exactly
the one it hid.

softRegisterAppLocally now answers true or false the way registerAppLocally
does, and all three redeploy paths read it before they claim anything.

The harness gate for this is repaired by the same change: suite 58 judges a
redeploy on the last envelope in the stream, and on the catastrophic path that
was removeAppLocally's own success message.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
softUninstallComponent and hardUninstallComponent take the BARE app name and
join it with the component's own name themselves. fdb226d fixed the two
operator-driven paths and left reinstallOldApplications, which passes the
already-joined name - so the monitoring key became `web_web_myapp`, the stop
targeted a monitor that does not exist, the live one kept sampling a container
being removed, and cleanupPorts got a name the install never used for its UPnP
description.

This is the path that actually runs: it is what redeploys a component when its
on-chain specification changes, on every node hosting the app, with no operator
involved. The API paths a person has to call by hand were the covered ones.

The test drives the real function through checkSynced, the installed-apps read
and the redeploy probability draw, so it pins the argument at the call site
rather than the helper's own contract.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Every app container was created with one 20MB log file. Docker does not trim a
full log file, it discards it - so the history an operator or the log viewer can
read swung between 20MB and NOTHING, and the moment it filled, 20MB went with
it. Measured: the same container, 400 lines written into a 4KB budget, kept 20
of them at max-file 1 and 107 at max-file 4.

Four 5MB files is the same 20MB of disk and only the oldest quarter is dropped
per rotation, so at least 15MB is always readable. `docker logs` reads across
the set, and nothing in FluxOS reads the file directly, so the change is
invisible to every reader.

The setting is fixed when a container is created, so this reaches an app when it
is next redeployed rather than all at once. Nothing needs tearing down for it.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
appLogStream has never been routed. routes.js wires /apps/applog to appLog and
/apps/applogpolling to appLogPolling and nothing else, and `git log -S` over
routes.js across every branch finds no route that ever named it. It traces to
766cff7, 2021-02-10, the ZelFlux rename - so it arrived already written and
already unrouted, survived the 2025 appsService split into appInspector, and was
called by nothing for four and a half years.

Its only consumer, dockerContainerLogsStream, goes with it: appLogStream was the
one caller.

It looked alive - its own privilege check, a content type, a place on the export
list, a describe block in dockerService.test.js - which is why 87ad281 and
7c6abcc both carried fixes for code nothing could execute. It is also still
broken one line below where those fixes landed: appInspector passed the error
OBJECT to res.write, which only takes a string or a Buffer, so routing it would
throw ERR_INVALID_ARG_TYPE from inside dockerode's callback and exit the node by
a shorter path than the one that was fixed.

/apps/applog already serves "show me the logs" and /apps/applogpolling serves
"keep showing me the logs". Nothing is lost.

The dockerContainerLogsStream describe in dockerService.test.js was mislabelled -
it exercises dockerContainerLogs - so it stays, under its own name.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…eader got to

/apps/applogpolling is what a browser polls on a timer to show an app's logs,
and it had two defects that a unit test could not see because both are about
what docker does rather than what FluxOS passes it.

COST. It asked for `follow: true`, which never closes, so the only way out was
a 1500ms timer - every poll took 1500ms to answer whether one line was waiting
or none. Measured against a live container: 1526ms, 1507ms, 1507ms, each
returning a single line. `follow: false` lets docker close the connection
itself, and with it go the PassThrough, the window, the closing flag, the four
stream handlers and the finally that existed only to release a connection that
never closed on its own.

LOSS. It asked for the last N lines and the reader replaced its view with them,
so anything written between two polls beyond N was never shown to anyone. The
`since` parameter did not help: it was a box a user typed in, never advanced,
and docker applies `tail` AFTER `since` anyway - so a burst of 500 lines with
tail:100 answers a reader asking for everything since T with the last 100 and
no sign the rest existed.

A reader is now given a position and hands it back. Verified against a real
daemon: docker's `since` is inclusive and millisecond-resolved, so the line
asked from always comes back - which is the proof there is no gap, and why the
position must never advance past a line already held. A line at .9265 is lost
forever to a reader that asked from .927.

The position is therefore a pair - the millisecond reached and how many lines
were delivered from it - and the overlap is dropped by COUNT, not by comparing
text: two writes of the same string in one millisecond are indistinguishable by
content, and a reader de-duplicating by value would drop the new one. The
dropping happens here, next to the docker socket, so no client reimplements it.
Opaque on the wire because clients and nodes upgrade independently.

A cursor arrives as a QUERY parameter: the route takes three optional path
segments and a fourth would not match, so a reader sending its position to a
node that predates this would get a 404 instead of logs. A request without one
behaves exactly as before, which is what keeps every deployed client working.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The cursor's correctness rests on docker semantics, and the unit tests pin them
against a crafted buffer - which is the author's belief about docker, not
docker. This is the real daemon, a container writing on its own schedule, and
the only assertion that matters end to end: across ten polls a second apart
against a container writing ten lines a second, every line is seen EXACTLY ONCE,
in order, with no gap.

The lines are numbered by the container itself, which is what makes that
checkable - a gap and a repeat are both visible in the sequence, and identical
lines would hide both. LOG_EVERY_MS is added to the test-app for it, in the same
env-var shape as EXIT_AFTER_S and BURN_CPU.

Also asserts five consecutive polls each answer in under a second, which is the
fleet-level proof the 1500ms timer is gone; a unit test with a stubbed docker
cannot make that claim.

Proved red: all four fail against the pre-change code on the same fleet. The
compatibility test failed there too, which it must not - it asserted
`rolledOver` is false, and an old node does not return the field at all, so it
was a test of the new code wearing a compatibility test's name. It now asserts
only what both answer.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The comment on listMountedFilesystems spent four lines on how the node-df
package it replaced computed sizes wrongly. node-df was removed from
package.json by the same commit, so the only thing that paragraph reliably does
now is send a reader looking for a dependency that is not there.

What it says about the current code - byte counts come from `--bytes`, so no
unit conversion is needed - is the line above it, and stays.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ing them all

getDockerContainerByIdOrName turned a name into an id by calling
listContainers({all: true}) and scanning the result. It has sixteen call sites -
start, stop, restart, remove, inspect, exec, stats, logs - so every operation on
one container enumerated every container on the node. A node running twenty apps
returned twenty records to answer a question about one, and the log endpoint paid
it on a timer for as long as a browser was left open.

Docker filters server-side, so one record comes back whatever the node is
running.

The exact name comparison stays and is load-bearing: docker's name filter is a
SUBSTRING match, so asking for `web` returns `fluxwebsite` too. The filter
narrows what comes back; it does not choose. Verified against a real daemon -
`websitelong` resolves to itself rather than to `website`, and `websit` is
refused although the filter returns `fluxwebsite` for it.

A raw docker id cannot be matched by a name filter, so it falls through to a
second request rather than making the other fifteen callers pay for a listing.
Only the reconciler passes one.

An earlier attempt proved existence with inspect() instead. The suite caught it:
callers like appDockerStop inspect immediately afterwards, so it traded one
listing for two inspects.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@MorningLightMountain713 MorningLightMountain713 changed the title fix: a missing container must not crash FluxOS, and a failed soft redeploy must not uninstall the app fix(apps): a missing container must not crash FluxOS, a failed redeploy must not uninstall the app, and a log poll must lose nothing Sep 4, 2026
MorningLightMountain713 added a commit that referenced this pull request Sep 4, 2026
… every other

100 was the first three-digit suite, and the number had a consequence nobody
chose: the runner orders suites heavy-first by numeric prefix and 100 sorts
lexically ahead of 28, so the newest suite launched first in every gate. 58 and
59 are taken by the PR #1794 lineage, so this takes 83.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…oint answers

Three defects with one root: a caller could not tell what had happened, so it
guessed, and every guess was wrong in a way that lost a running application.

REFUSED IS NOT DESTROYED. registerAppLocally answered `false` both for "another
operation holds the node, I touched nothing" and for "I got part way, failed,
and have already torn the app down". The redeploy paths read that as the second.
So: a component redeploy tears the component down, the spawner starts an
unrelated install inside composedDelay - nothing in appSpawner consults any
in-progress flag - the reinstall is refused, and the redeploy answers a
five-second scheduling collision by force-uninstalling a healthy app and
broadcasting the removal. That is the shape of the incident in this PR's own
section 2, reintroduced by the change that stopped it reporting false success.

InstallOutcome is a frozen enum, in the shape of Privilege, and its docblock
says what Privilege's cannot: nothing answers these to a client, so the values
are ours as well as the names. All eleven call sites moved with the return type
rather than being left to be found later, because every value is truthy and a
site left on `if (!outcome)` reads a refusal as a success. The spawner no longer
matches on error text to work out which case it is in - its own comment had been
complaining about exactly that.

THE INSTALLER CLOSED A RESPONSE IT DID NOT OPEN. 66419b0 applied that rule to
softRegisterAppLocally and left registerAppLocally, which is the HARD redeploy's
reinstall - six close sites, four guards, the success path, and a teardown
passing endResponse true. So a failed hard redeploy ended on removeAppLocally's
own "was successfuly removed", a SUCCESS envelope, while the app was destroyed;
the real error was written into a response that had already closed. Three more
of those sites were in softRedeploy's and hardRedeploy's catches. There are now
none: a grep for the pattern across ZelBack/src returns nothing, and
installAppLocally and testAppInstall each close their own response once.

SILENCE IS NOT AN ANSWER. A redeploy that gives up on purpose - the removal
failed part way, so the app is not known to be down and the reconciler converges
it - returned without writing anything. The stream then closed on a progress
line and answered 200, so a redeploy that never happened read as one that did.
The warning already existed; it was only being told to the log.

Two things the tests were not doing. `should return false if app already
installed` never reached the guard it named - the guard and the catch both
answered `false`, so it passed on the catch. And a test of mine asserting the
silent path reports could not fail: it drove a throw, which reaches the catch,
which always wrote. Both are re-pointed, and the second was proved red by making
the path silent again.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…at has one

Four defects in the position added by ae5196d, all of them assumptions about
docker that the tests could not see because the fixtures encoded the same
assumptions.

THE LOG IS NOT IN TIMESTAMP ORDER. A container writing to stdout AND stderr has
two writers, each stamping its line before the write is serialised into the
file: 3,304 backwards steps in 40,000 lines, measured on a real daemon. `count`
meant "delivered lines whose millisecond equals the last one's", which misses the
already-delivered lines stamped just before `ms`, so the skip came up short and
the tail of each page was delivered twice - 19 and 57 duplicates over two walks
of a real log, 0 missing in both. `count` is now a place in the sequence docker
returns, and `ms` is the NEWEST timestamp delivered rather than the last line's,
which is the half that keeps it monotonic. Walked end to end against a container
alternating both streams: 12,000 lines, 0 duplicates, 0 missing, at two page
sizes. test-app.c now alternates streams, because a stdout-only writer cannot
produce the case and so cannot test for it.

`since` ALONE RE-READS THE WHOLE LOG. There is no index to seek with: docker
decodes forward from the start of the oldest file until it finds the first match.
74ms at 3.5MB, 273ms at 14MB, growing - and the retention floor in 5f18c2d
guarantees the log is always full, so that was the steady state for every poll of
every open viewer. With `tail` present docker opens at the END and answers
byte-for-byte the same in ~4ms, flat. A positioned read now sends tail = maxLines
+ 1; the extra frame says whether the whole matching set fitted, and only a reader
more than a page behind pays for the scan, once, to catch up. Steady-state poll
measured at 14-15ms against both a 3.5MB and a 14MB log.

A `since` FILTER IS NOT A POSITION. A date typed into a log viewer was turned
into one, which dropped its line count - "the last 100 lines since Tuesday"
became the whole log - and answered rolledOver, a data-loss warning, because a
hand-typed timestamp does not land on a log line. It is a filter: it keeps tail
and can never report a position it never had.

AND `all` IS A DOWNLOAD, NOT A PAGE. The 5000-line cap applied to it and kept the
OLDEST of them, so a caller asking for every line was handed the START of the log
and never its end. Only a positioned reader is capped now, because only a
positioned reader comes back for the rest.

Three existing tests set their scenario up by capping a cursor-less call - they
were resting on the behaviour that broke the download - and now use a position.
Suite 59 covers both restored shapes on a fleet.

Also: a removal addressed by a raw docker id is no longer recorded as FluxOS's
own. The reconciler only ever asks about app containers by identifier, so that
entry could never be read, and clearFluxRemovedContainers matches on an app name
a hex id does not carry, so it could never be dropped. And docker's name filter
is a regex, not a substring match - harmless for the names the network permits,
wrong in the wording.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

@Cabecinha84 Cabecinha84 left a comment

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Blocking: advancedWorkflows.js:1157 — the teardown outlives the response it writes into

// softRegisterAppLocally, catch block
const appUninstaller = require('./appUninstaller');
appUninstaller.removeAppLocally(appSpecs.name, res, true, false); // <- no await
return InstallOutcome.FAILED;

registerAppLocally (the hard path) awaits its equivalent. This one does not — and it is pre-existing, but the PR makes it
harmful. Before, endResponse defaulted to true, so the floating teardown owned the close and its output reached the
client. Now it is false and the endpoint closes in a finally. Ordering:

  1. redeployComponentAPI → softRedeployComponent → softRegisterAppLocally throws (image pull, port conflict, docker error —
    routine).
  2. Catch starts removeAppLocally and returns FAILED synchronously. removeAppLocally runs to its first await
    dbHelper.findOneInDatabase(...) (appUninstaller.js:842) and suspends before any of its progress writes.
  3. Caller sees !== INSTALLED → writes "not reinstalled (failed)" → returns.
  4. redeployComponentAPI's finally → res.end().
  5. removeAppLocally resumes → hardUninstallComponent(..., res, ...) → dozens of res.write into a closed response.

I checked whether that is actually fatal on Node 22, because it matters:

destroyed=true, finished=true -> write is a silent no-op
destroyed=false, finished=true, writableFinished=false -> UNCAUGHT: ERR_STREAM_WRITE_AFTER_END, exit 7

The second case is a response whose body is still flushing — a streaming redeploy endpoint to a real browser over a real
network. So section 5's premise is right, and this call re-arms it. Same for redeployAPI → softRedeploy (line 1425). Fix
is one word:

await appUninstaller.removeAppLocally(appSpecs.name, res, true, false);

Secondary effects of the same missing await, worth fixing regardless: the endpoint answers and clears
softRedeployInProgress while a forced uninstall is still in flight.

Why the tests miss it: does not report a component redeploy that never reinstalled the component
(advancedWorkflows.test.js:4480) drives exactly this path, but appUninstaller.removeAppLocally is a sinon stub that
resolves instantly and writes nothing, so res.writesAfterEnd stays empty. That is the same
test-double-is-more-forgiving-than-reality problem the PR body says it went and fixed elsewhere.


Non-blocking

  1. truncated changed meaning for existing clients. Was logs.length >= lineCount; now it is only ever true for a positioned
    reader. Every deployed viewer without a cursor now gets truncated: false always. The compat table covers logs
    faithfully but not this field.
  2. reinstallOldApplications still ignores InstallOutcome at advancedWorkflows.js:4335, 4455, 4562, 4569. On REFUSED
    (spawner holds installationInProgress) the component has been uninstalled and not put back, and the loop then logs
    Composed application … updated and restarts the app. Pre-existing, but this is the automatic path section 4 argues is
    the important one, and the new enum makes it a two-line check.
  3. fluxRemovedContainers has no TTL and is not dropped on read. Only a successful appDockerCreate or a full
    removeAppLocally clears an entry. If recreateMissingContainers keeps failing, container_vanished stays suppressed for
    that container for the life of the process. Dropping the entry when the reconciler consults it would close that.
  4. Catch-up re-read cost. When a reader is more than a page behind, the unbounded docker logs read pulls the whole
    retained log (up to 20 MB) into a Buffer plus a full line array, once per poll until caught up. Bounded and rare, but
    it is a per-request memory spike on a memory-tight node. A very large tail instead of none would keep the seek-from-end
    property.
  5. Same-class defect one function away: appInspector.appExec's callback does res.write(errorResponse) with an object, from
    inside a dockerode callback — a TypeError with no catcher, i.e. the exact defect section 10 describes in the deleted
    appLogStream. And dockerContainerExec does if (err) callback(err) without returning, then dereferences mystream.
    Pre-existing, out of scope, but it is the next one.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants