Skip to content

fix: server removal leaves orphaned Discord channels; pairing pushes are invisible in the log - #81

Merged
HandyS11 merged 5 commits into
developfrom
fix/server-removal-lock-and-pairing-logs
Sep 1, 2026
Merged

fix: server removal leaves orphaned Discord channels; pairing pushes are invisible in the log#81
HandyS11 merged 5 commits into
developfrom
fix/server-removal-lock-and-pairing-logs

Conversation

@HandyS11

@HandyS11 HandyS11 commented Aug 30, 2026

Copy link
Copy Markdown
Owner

Two bugs found while debugging a live "I deleted the server but it didn't work, and now the in-game pair button does nothing" report.

1. Server removal could leave orphaned Discord channels

ServerRemovalService deleted the RustServer row outside the guild's provisioning lock, taking the lock only for the Discord teardown:

stop socket -> delete row (no lock) -> teardown (takes lock)

A reconcile already in flight has taken its "does this server exist?" decision before the row goes away, and its Discord REST calls are slow (rate limited). It therefore finishes re-creating the category and channels that teardown is about to remove, then faults on the FK when it writes its ProvisionedMessages row. Its rows roll back, so teardown has no record of the resources it just re-created and leaves them behind — the server disappears from the bot but its Discord channels survive.

Observed in a live log:

[21:18:42 ERR] SQLite Error 19: 'FOREIGN KEY constraint failed'
               INSERT INTO "ProvisionedMessages" (... "RustServerId" ...)
               at WorkspaceReconciler.EnsureMessagesAsync
[21:18:42 WRN] ReconcileServer skipped: server 6bfd3d56-… not found in guild 890249866905792542   (x23)

GuildPurgeService already guards exactly this hazard, and says so in a comment — it holds the lock across the whole purge. The per-server path never got the same treatment. This PR mirrors it:

  • New ServerPurgeService holds the provisioning lock across both the row delete and the teardown.
  • New lock-free WorkspaceTeardownService.RemoveServerCoreAsync, matching the existing ResetGuildCoreAsync pattern, so the purge cannot deadlock re-acquiring.
  • IServerWorkspaceRemover now owns both steps and returns whether a row was deleted; ServerRemovalService reduces to "stop the socket, then delegate".

2. Pairing notifications were invisible in the log

RustPlusFcmPairingSource only logged when dispatching a notification threw, and PairingHandler's two entity drops were at Debug. So a pairing push that never arrives and one that arrives and is handled cleanly produced identical output: nothing. That makes "I pressed pair in game and nothing happened" impossible to diagnose — you cannot tell whether Rust+ delivered the push at all.

  • Log every notification on arrival at Information (kind, server name, ip:port, facepunch id, entity id). PlayerToken is deliberately not logged; it is a secret.
  • Log the routing decision in PairingHandler: new server prompting in #setup, or known server credential upsert.
  • Raise the unknown-Facepunch-server and unrouted-entity-kind drops from Debug to Information — both silently discard a real pairing.

Testing

New ServerPurgeServiceTests covers the race directly: a contending acquire attempted from inside the row-delete callback must time out, proving the lock is held across the delete.

Written test-first. Verified it fails against the old ordering by temporarily reintroducing it:

PurgeServer_HoldsProvisioningLock_WhileTheServerRowIsDeleted
  Expected: False, Actual: True

Full suite: 1318 passed, 1 skipped.

dotnet format reports 443 violations repo-wide, but they are pre-existing — the identical count is present on a clean develop tree, and none are in files touched here. The ReSharper pre-push hook is satisfied.

🤖 Generated with Claude Code

Also included

  • docs/development/running-locally.md — a "Running detached" section (setsid/nohup invocation, following bot.log, stopping the host).
  • .gitignore — the existing *.log does not match rotated names like bot.log.1, so rotating a detached run left old logs showing as untracked. Now ignores *.log.* too.

Copilot AI lite review requested due to automatic review settings August 30, 2026 20:03

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

🟡 Changes recommended

ServerPurgeService currently deletes the RustServer row before teardown, which can remove provisioning records needed to locate and delete Discord resources (risking persistent orphans), and the PR also includes large unrelated doc additions that should be confirmed/split.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Pull request overview

This PR targets two production-debug issues in RustPlusBot: preventing orphaned Discord workspace resources when a Rust server is removed, and making Rust+ pairing pushes visible/diagnosable via higher-signal logging.

Changes:

  • Introduces a per-server purge path (ServerPurgeService) intended to hold the guild provisioning lock across server-row deletion and workspace teardown, and updates the Connections removal flow to delegate to it.
  • Improves pairing diagnostics by logging pairing push arrival and key routing/drop decisions at Information.
  • Adds new “vending machine tracking” spec/plan documentation under docs/superpowers/.
File summaries
File Description
tests/RustPlusBot.Features.Workspace.Tests/Teardown/ServerPurgeServiceTests.cs Adds tests for purge locking and ordering behavior.
tests/RustPlusBot.Features.Connections.Tests/ServerRemovalServiceTests.cs Updates removal-flow tests to reflect the new delegation to IServerWorkspaceRemover.
src/RustPlusBot.Features.Workspace/WorkspaceServiceCollectionExtensions.cs Switches IServerWorkspaceRemover DI binding to ServerPurgeService.
src/RustPlusBot.Features.Workspace/Teardown/WorkspaceTeardownService.cs Adds lock-free RemoveServerCoreAsync for use by a higher-level purge that already holds the lock.
src/RustPlusBot.Features.Workspace/Teardown/ServerPurgeService.cs New service intended to serialize row deletion + teardown under the provisioning lock.
src/RustPlusBot.Features.Workspace/Teardown/IServerWorkspaceRemover.cs Expands contract to include deleting the server row and returning whether a row was removed.
src/RustPlusBot.Features.Pairing/Pairing/PairingHandler.cs Raises visibility of entity-drop logs and logs pairing routing decisions.
src/RustPlusBot.Features.Pairing/Listening/RustPlusFcmPairingSource.cs Logs pairing notifications on arrival (not only on dispatch failure).
src/RustPlusBot.Features.Connections/Removal/ServerRemovalService.cs Simplifies to “stop socket then delegate row delete + teardown” to IServerWorkspaceRemover.
docs/superpowers/specs/2026-08-17-vending-machine-tracking-design.md Adds vending tracking design doc.
docs/superpowers/plans/2026-08-17-vending-machine-tracking.md Adds vending tracking implementation plan doc.
Review details
  • Files reviewed: 10/11 changed files
  • Comments generated: 4
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment on lines +21 to +30
// Hold the per-guild provisioning lock across BOTH steps. A reconcile that is already in flight took
// its "does this server exist?" decision before the row went away; if the lock were free between the
// delete and the teardown it would finish re-creating the category and channels that teardown has
// just removed (and fault on the FK when it writes its ProvisionedMessages row), leaving orphaned
// Discord resources behind. Use the lock-free teardown core since we already hold the lock —
// RemoveServerAsync would deadlock re-acquiring it.
using var handle = await provisioningLock.AcquireAsync(guildId, cancellationToken).ConfigureAwait(false);
var removed = await servers.RemoveAsync(guildId, serverId, cancellationToken).ConfigureAwait(false);
await teardown.RemoveServerCoreAsync(guildId, serverId, cancellationToken).ConfigureAwait(false);
return removed;

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

Confirmed and fixed in 0733c4f. Verified the cascade is real at both layers — ProvisionedChannelConfiguration.cs:19-23, ProvisionedCategoryConfiguration.cs:18-21 and ProvisionedMessageConfiguration.cs:19-22 all use DeleteBehavior.Cascade, and the live schema confirms ON DELETE CASCADE on all three FKs.

ServerPurgeService now runs the lock-free teardown first, then deletes the row, both under one continuous hold of the provisioning lock.

This is also a better explanation of the original report than the one in the PR description: deleting the row first cascaded the provisioning records away, so teardown had no ids to look up and deleted nothing. That is the primary cause of the orphaned channels, with the lock race a second contributor.

The reorder then exposed a further defect. WorkspaceStore.DeleteScopeAsync bulk-deletes via ExecuteDeleteAsync, which bypasses the change tracker, while GetChannelsAsync/GetCategoryAsync track what they read (no AsNoTracking anywhere in the store). The stale tracked rows were then re-issued as client-side cascade deletes by the next SaveChanges and failed with expected to affect 1 row(s), but actually affected 0. Those entries are now detached after the bulk delete. GuildPurgeService runs the same teardown-then-delete sequence and was exposed to this too.

Comment on lines +70 to +86
public async Task PurgeServer_DeletesTheRow_ThenTearsDownTheScope()
{
var (sut, servers, store, _) = NewHarness();
var serverId = Guid.NewGuid();
servers.RemoveAsync(GuildId, serverId, Arg.Any<CancellationToken>()).Returns(true);

var removed = await sut.RemoveServerAsync(GuildId, serverId);

Assert.True(removed);
#pragma warning disable VSTHRD110 // Received.InOrder requires unawaited calls inside its synchronous ordering lambda.
Received.InOrder(() =>
{
servers.RemoveAsync(GuildId, serverId, Arg.Any<CancellationToken>());
store.DeleteScopeAsync(GuildId, serverId, Arg.Any<CancellationToken>());
});
#pragma warning restore VSTHRD110
}

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

Fixed. The assertion is inverted to teardown-then-delete.

The deeper problem you point at is that this test could not have caught the bug at all — it substitutes IWorkspaceStore, so no cascade ever runs and either ordering passes. Added PurgeServer_DeletesTheDiscordChannels_EvenThoughTheRecordsCascadeWithTheRow, which runs over a real migrated BotDbContext and a real WorkspaceStore with only the Discord gateway substituted, and asserts the gateway is actually asked to delete each channel and the category.

Verified it reproduces the production failure by temporarily restoring the delete-first ordering:

PurgeServer_DeletesTheDiscordChannels_EvenThoughTheRecordsCascadeWithTheRow
  Expected to receive exactly 1 call matching: DeleteChannelAsync(1, 901, any CancellationToken)
  Actually received no matching calls.

Full suite: 1399 passed, 1 skipped.

Comment on lines 55 to +58
services.AddScoped<IServerInfoRefresher, ServerInfoRefresher>();
services.AddScoped<WorkspaceTeardownService>();
services.AddScoped<IWorkspaceTeardownService>(sp => sp.GetRequiredService<WorkspaceTeardownService>());
services.AddScoped<IServerWorkspaceRemover>(sp => sp.GetRequiredService<WorkspaceTeardownService>());
services.AddScoped<IServerWorkspaceRemover, ServerPurgeService>();

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

Fixed in 0733c4f. The comment now states that WorkspaceTeardownService is registered once with IWorkspaceTeardownService resolving off that same scoped instance, and that the purge services take it as a concrete dependency to reach its lock-free cores while holding the provisioning lock themselves.

Comment on lines +1 to +8
# Vending Machine Search and Tracking Implementation Plan

> **For agentic workers:** REQUIRED SUB-SKILL: Use superpowers:subagent-driven-development (recommended) or superpowers:executing-plans to implement this plan task-by-task. Steps use checkbox (`- [ ]`) syntax for tracking.

**Goal:** Let players search every vending machine on a Rust server for an item, register their own shop by grid cell, and get Discord notifications when a rival undercuts them or when their own listings sell out.

**Architecture:** Vending data rides along on the existing 5-second `GetMapMarkers` poll — no new Rust+ request. The connection supervisor publishes a `VendingMachinesObservedEvent`; `Features.Vending` keeps a wholesale-replaced in-memory index per server, and two **pure** evaluators turn (index + tracks) into a desired set of notifications. A relay reconciles that desired set against persisted Discord message ids by posting, editing, or deleting. Only track registrations and posted message ids touch SQLite.

Copy link
Copy Markdown
Owner Author

Choose a reason for hiding this comment

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

Already resolved — this comment was made against a stale diff. The branch had been cut from a local develop that carried two unpushed vending-machine doc commits (89b88fd, 20ba624), so they showed up in the PR diff against origin/develop.

The branch has since been rebased onto origin/develop and those commits are no longer part of it; they remain on local develop to be pushed separately. The PR now touches 11 files, none of them vending-machine docs.

HandyS11 and others added 4 commits August 31, 2026 00:57
Removing a server deleted its RustServer row outside the guild's
provisioning lock and only took the lock for the Discord teardown:

    stop socket -> delete row (no lock) -> teardown (takes lock)

A reconcile already in flight has taken its "does this server exist?"
decision before the row goes away, and its Discord REST calls are slow
(rate limited). It therefore finishes re-creating the category and
channels that teardown is about to remove, then faults on the FK when it
writes its ProvisionedMessages row. Its rows roll back, so teardown has
no record of the resources it just re-created and leaves them behind --
the server disappears from the bot but its Discord channels survive.

GuildPurgeService already guards this hazard by holding the lock across
the whole purge. Mirror that for the per-server path: ServerPurgeService
holds the lock across both the row delete and the teardown, using a new
lock-free RemoveServerCoreAsync (matching the existing ResetGuildCoreAsync
pattern) so it cannot deadlock re-acquiring.

IServerWorkspaceRemover now owns both steps and reports whether a row was
deleted, leaving ServerRemovalService to stop the socket and delegate.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
RustPlusFcmPairingSource only logged when dispatching a notification
threw, and PairingHandler's two entity drops were at Debug. A pairing
push that never arrives and one that arrives and is handled cleanly
therefore produced identical output: nothing. That makes "I pressed pair
in game and nothing happened" impossible to diagnose from the log -- you
cannot tell whether Rust+ delivered the push at all.

Log every notification on arrival at Information (kind, server name,
ip:port, facepunch id, entity id), plus the routing decision in
PairingHandler: new server prompting in #setup, or known server credential
upsert. PlayerToken is deliberately not logged; it is a secret.

Raise the unknown-Facepunch-server and unrouted-entity-kind drops from
Debug to Information -- both silently discard a real pairing.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Parameter-per-line on the new LoggerMessage declarations and member
ordering in WorkspaceTeardownService. No behaviour change.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Adds the "Running detached" section to the local-run guide: the
setsid/nohup invocation, following bot.log, and stopping the host.

The .gitignore's `*.log` does not match rotated names like `bot.log.1`,
so rotating a detached run's output left the old logs showing up as
untracked. Ignore `*.log.*` too.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@HandyS11
HandyS11 force-pushed the fix/server-removal-lock-and-pairing-logs branch from 4a70bf6 to 93aa456 Compare August 30, 2026 22:59
ProvisionedCategories, ProvisionedChannels and ProvisionedMessages all
declare ON DELETE CASCADE against RustServers. Deleting the row first
therefore took the provisioning records with it, so the teardown that
followed had no Discord channel or category ids left to look up and
silently deleted nothing -- the channels survived as orphans. That is the
primary cause of "removed the server but its Discord channels stayed",
with the lock race a second contributor.

Run the lock-free teardown first, while the records still exist, then
delete the row -- both still under one continuous hold of the guild's
provisioning lock.

The previous ordering test could not have caught this: it substituted
IWorkspaceStore, so no cascade ever ran. Replaced with a test over a real
migrated BotDbContext and a real WorkspaceStore that asserts the gateway
is actually asked to delete each channel and the category.

That test then exposed a second defect. WorkspaceStore.DeleteScopeAsync
bulk-deletes via ExecuteDeleteAsync, which bypasses the change tracker,
while GetChannelsAsync/GetCategoryAsync track what they read. The stale
tracked rows were re-issued as client-side cascade deletes by the next
SaveChanges and failed with "expected to affect 1 row(s), but actually
affected 0". Detach them after the bulk delete so the tracker matches the
database. GuildPurgeService runs the same teardown-then-delete sequence
and was exposed to this too.

Also corrects the DI comment: IServerWorkspaceRemover no longer resolves
off the shared WorkspaceTeardownService instance.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@HandyS11
HandyS11 merged commit e6b4acb into develop Sep 1, 2026
3 checks passed
@HandyS11
HandyS11 deleted the fix/server-removal-lock-and-pairing-logs branch September 1, 2026 18:39
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