diff --git a/plugins/velocity/src/main/java/best/lolicon/felis/velocity/WaitingRouter.java b/plugins/velocity/src/main/java/best/lolicon/felis/velocity/WaitingRouter.java index 944596b..5dcdf5a 100644 --- a/plugins/velocity/src/main/java/best/lolicon/felis/velocity/WaitingRouter.java +++ b/plugins/velocity/src/main/java/best/lolicon/felis/velocity/WaitingRouter.java @@ -46,7 +46,8 @@ import java.util.function.LongSupplier; * reports ready, transfers everyone waiting on it. A waiter stays as long as its * server is on the way up, through the operator's restart backoff, and drops out on a * successful transfer, when the player leaves the proxy, when the start is given up or - * the server stopped, or when felis-api stops answering for the wait window. + * the server stopped, or when felis-api stops answering for the wait window. A transfer + * that fails without the backend saying why queues the player again for another dial. * *

Every transition out of login is checked against felis-api's link status, and * command/menu queue entries are checked the same way. The wake is then gated @@ -79,6 +80,9 @@ public final class WaitingRouter { // The login gate re-sends its release with backoff (and during a felis-api outage // on every retry), so a denial line is shown at most once per this interval. private static final long GATE_NOTICE_INTERVAL_MILLIS = 15_000L; + // How many times a player is dialled into a server that fails the connect without + // saying why. The retries ride the queue, a tick apart, each after a fresh ready poll. + private static final int TRANSFER_ATTEMPTS = 3; private final ProxyServer proxy; private final Logger log; @@ -249,7 +253,8 @@ public final class WaitingRouter { NamedTextColor.RED)); return; } - transfer(player, lobbyServer, lobby.get()); + // One dial: the lobby is no queue target, and the player can simply ask again. + transfer(player, lobbyServer, lobby.get(), false, TRANSFER_ATTEMPTS); } /** @@ -505,7 +510,7 @@ public final class WaitingRouter { if (w.fromMenu && listener != null) { listener.onReady(player, w.serverName); } - transfer(player, w.serverName, backend.get()); + transfer(player, w.serverName, backend.get(), w.fromMenu, w.attempts + 1); } } @@ -644,7 +649,7 @@ public final class WaitingRouter { if (fromMenu && listener != null) { listener.onReady(player, serverName); } - transfer(player, serverName, backend.get()); + transfer(player, serverName, backend.get(), fromMenu, 1); return true; } @@ -724,7 +729,7 @@ public final class WaitingRouter { : "Starting « " + serverName + " » — you'll be moved in automatically.", NamedTextColor.GRAY)); } - waiting.put(id, new Waiter(serverName, clock.getAsLong(), fromMenu)); + waiting.put(id, new Waiter(serverName, clock.getAsLong(), fromMenu, 0)); } // The server's start failed and its automatic retries are spent: nothing more is @@ -745,26 +750,51 @@ public final class WaitingRouter { NamedTextColor.RED)); } - private void transfer(Player player, String serverName, RegisteredServer backend) { + /** + * transfer dials a player into a server; attempt numbers this dial among the ones + * made for the same move. A connect that fails without the backend saying why — the + * server went away between the ready poll and the dial, its port is not listening + * yet, the network dropped — puts the player back in the queue until + * {@link #TRANSFER_ATTEMPTS} dials are spent: a later tick polls the server again, + * registers the address it reports and dials once more. A refusal that carries a + * reason (ban, whitelist, full, mods) is final at once, and so is a dial another + * connection or a pre-connect listener pre-empted. + */ + private void transfer(Player player, String serverName, RegisteredServer backend, + boolean fromMenu, int attempt) { player.createConnectionRequest(backend).connect().whenComplete((result, err) -> { - if (err != null || (result != null && !result.isSuccessful())) { - plugin.stats().count(ProxyStats.Event.TRANSFER_FAILED); - log.warn("Felis: transfer of {} to {} failed: {}", player.getUniqueId(), serverName, - err != null ? err.toString() : result.getStatus()); - boolean zh = FelisVelocityPlugin.zh(player); - Component line = Component.text( - zh ? "无法把你连接到「" + serverName + "」。" - : "Couldn't connect you to « " + serverName + " ».", - NamedTextColor.RED); - // A backend that refuses the login says why (ban, whitelist, full, mods); - // "please try again" is wrong advice for all of those. - Optional reason = result == null ? Optional.empty() : result.getReasonComponent(); - line = reason.isPresent() - ? line.append(Component.text(zh ? " 原因：" : " Reason: ", NamedTextColor.RED)) - .append(reason.get()) - : line.append(Component.text(zh ? "请重试。" : " Please try again.", NamedTextColor.RED)); - player.sendMessage(line); + if (err == null && (result == null || result.isSuccessful())) { + return; } + plugin.stats().count(ProxyStats.Event.TRANSFER_FAILED); + log.warn("Felis: transfer of {} to {} failed (attempt {}/{}): {}", player.getUniqueId(), serverName, + attempt, TRANSFER_ATTEMPTS, err != null ? err.toString() : result.getStatus()); + boolean zh = FelisVelocityPlugin.zh(player); + boolean unexplained = err != null + || (result.getStatus() == ConnectionRequestBuilder.Status.SERVER_DISCONNECTED + && result.getReasonComponent().isEmpty()); + // putIfAbsent: a player who queued for another server meanwhile keeps that wait. + if (unexplained && attempt < TRANSFER_ATTEMPTS + && waiting.putIfAbsent(player.getUniqueId(), + new Waiter(serverName, clock.getAsLong(), fromMenu, attempt)) == null) { + player.sendMessage(Component.text( + zh ? "没能连上「" + serverName + "」，稍后自动重试……" + : "Couldn't reach « " + serverName + " »; trying again shortly…", + NamedTextColor.YELLOW)); + return; + } + Component line = Component.text( + zh ? "无法把你连接到「" + serverName + "」。" + : "Couldn't connect you to « " + serverName + " ».", + NamedTextColor.RED); + // A backend that refuses the login says why (ban, whitelist, full, mods); + // "please try again" is wrong advice for all of those. + Optional reason = result == null ? Optional.empty() : result.getReasonComponent(); + line = reason.isPresent() + ? line.append(Component.text(zh ? " 原因：" : " Reason: ", NamedTextColor.RED)) + .append(reason.get()) + : line.append(Component.text(zh ? "请重试。" : " Please try again.", NamedTextColor.RED)); + player.sendMessage(line); }); } @@ -786,6 +816,7 @@ public final class WaitingRouter { final String serverName; final boolean fromMenu; // true → notify the felis:control face on transfer final long sinceMillis; + final int attempts; // dials into serverName already made and failed // Only the drain touches these, one tick at a time (the ticking flag orders // the ticks), so they need no further synchronization. long deadlineMillis; @@ -793,9 +824,10 @@ public final class WaitingRouter { int restartsSeen; boolean stopSeen; - Waiter(String serverName, long nowMillis, boolean fromMenu) { + Waiter(String serverName, long nowMillis, boolean fromMenu, int attempts) { this.serverName = serverName; this.fromMenu = fromMenu; + this.attempts = attempts; this.sinceMillis = nowMillis; this.deadlineMillis = nowMillis + WAIT_TIMEOUT_MILLIS; this.noticedMillis = nowMillis; diff --git a/plugins/velocity/test/best/lolicon/felis/velocity/Fakes.java b/plugins/velocity/test/best/lolicon/felis/velocity/Fakes.java index 6bb481c..e8f9d36 100644 --- a/plugins/velocity/test/best/lolicon/felis/velocity/Fakes.java +++ b/plugins/velocity/test/best/lolicon/felis/velocity/Fakes.java @@ -19,6 +19,7 @@ import java.io.IOException; import java.io.OutputStream; import java.lang.reflect.InvocationHandler; import java.lang.reflect.Proxy; +import java.net.ConnectException; import java.net.InetSocketAddress; import java.nio.charset.StandardCharsets; import java.util.ArrayList; @@ -239,6 +240,8 @@ final class Fakes { volatile String virtualHost; volatile RegisteredServer current; volatile boolean connectSucceeds = true; + /** connectThrows fails every connect the way an unreachable backend does, with no result. */ + volatile boolean connectThrows; volatile String disconnectedWith; final List messages = Collections.synchronizedList(new ArrayList<>()); /** @@ -331,6 +334,10 @@ final class Fakes { status = ConnectionRequestBuilder.Status.CONNECTION_CANCELLED; } else { connects.add(dest.getServerInfo().getName()); + if (connectThrows) { + return CompletableFuture.failedFuture( + new ConnectException("Connection refused")); + } status = connectSucceeds && refusal == null ? ConnectionRequestBuilder.Status.SUCCESS : ConnectionRequestBuilder.Status.SERVER_DISCONNECTED; diff --git a/plugins/velocity/test/best/lolicon/felis/velocity/WaitingRouterTest.java b/plugins/velocity/test/best/lolicon/felis/velocity/WaitingRouterTest.java index 24febd0..19815d2 100644 --- a/plugins/velocity/test/best/lolicon/felis/velocity/WaitingRouterTest.java +++ b/plugins/velocity/test/best/lolicon/felis/velocity/WaitingRouterTest.java @@ -586,24 +586,87 @@ public final class WaitingRouterTest { () -> log.count("WARN", "join-event for " + p.id + " on beta failed (status=500)") == 1); api.joinStatus = 204; - // A transfer the backend refuses is counted, logged and told. - Fakes.FakePlayer refused = player(null, true); - refused.current = lobby; - refused.connectSucceeds = false; - router.enqueueFromInvite(refused.player, "beta"); - // The chat line is the last thing the failure path does; the count comes first. - Fakes.await("failed transfer: told", () -> refused.said("Couldn't connect you to « beta »")); - assertEq("failed transfer counted", 1L, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); - assertEq("failed transfer: logged", 1, log.count("WARN", "transfer of " + refused.id + " to beta failed")); + // A connect that fails without the backend saying why puts the player back in the + // queue; the next tick polls the server again and dials once more. + long failed = plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED); + int queued = router.waitingCount(); + Fakes.FakePlayer flaky = player(null, true); + flaky.current = lobby; + flaky.connectThrows = true; + router.enqueueFromInvite(flaky.player, "beta"); + // The chat line is the last thing the failure path does; the requeue comes first. + Fakes.await("unreachable: told it retries", () -> flaky.said("Couldn't reach « beta »; trying again shortly")); + assertEq("unreachable: queued again", queued + 1, router.waitingCount()); + assertEq("unreachable: counted", failed + 1, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); + assertEq("unreachable: logged", 1, + log.count("WARN", "transfer of " + flaky.id + " to beta failed (attempt 1/3)")); + assertEq("unreachable: no final word yet", false, flaky.said("Couldn't connect you")); + flaky.connectThrows = false; + int polls = api.count("GET " + SERVERS + "beta/status"); + router.tick(); + assertEq("retry: polled again", polls + 1, api.count("GET " + SERVERS + "beta/status")); + assertEq("retry: dialled again, and in", List.of("beta", "beta"), List.copyOf(flaky.connects)); + assertEq("retry: out of the queue", queued, router.waitingCount()); + assertEq("retry: nothing more counted", failed + 1, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); - // A backend that kicks the login says why; "please try again" is wrong for a ban. + // The dials are bounded: a backend that keeps dropping them gets the final word on + // the third. A menu wait stays one through its retries, so the lobby hears each. + List told = Collections.synchronizedList(new ArrayList<>()); + router.setMenuTransferListener((pl, server) -> told.add(pl.getUsername() + "@" + server)); + Fakes.FakePlayer dropped = player(null, true); + dropped.current = lobby; + dropped.connectSucceeds = false; + router.enqueueFromMenu(dropped.player, "beta"); + Fakes.await("dropped: queued again", () -> dropped.said("Couldn't reach « beta »; trying again shortly")); + router.tick(); + assertEq("dropped: second dial", 2, dropped.connects.size()); + assertEq("dropped: queued after the second", queued + 1, router.waitingCount()); + router.tick(); + assertEq("dropped: third dial", 3, dropped.connects.size()); + assertEq("dropped: given up", queued, router.waitingCount()); + assertEq("dropped: told to try again", true, dropped.said("Couldn't connect you to « beta ». Please try again.")); + assertEq("dropped: one final word", 1, count(dropped.messages, "Couldn't connect you")); + assertEq("dropped: every dial counted", failed + 4, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); + String at = dropped.name + "@beta"; + assertEq("dropped: the lobby told before every dial", List.of(at, at, at), List.copyOf(told)); + router.tick(); + assertEq("dropped: no fourth dial", 3, dropped.connects.size()); + + // A player already waiting for another server keeps that wait: the failed join is + // told as final instead of replacing it. + Fakes.FakePlayer busy = player(null, true); + busy.current = lobby; + router.enqueueFromCommand(busy.player, "zeta"); + Fakes.await("busy: waiting for zeta", () -> router.waitingCount() == queued + 1); + busy.connectThrows = true; + router.enqueueFromInvite(busy.player, "beta"); + Fakes.await("busy: told", () -> busy.said("Couldn't connect you to « beta ». Please try again.")); + router.tick(); + assertEq("busy: beta not dialled again", 1, busy.connects.size()); + assertEq("busy: still waiting for zeta", queued + 1, router.waitingCount()); + router.onDisconnect(new DisconnectEvent(busy.player, DisconnectEvent.LoginStatus.SUCCESSFUL_LOGIN)); + + // A pre-connect listener that cancels the move is final too. + Fakes.FakePlayer cancelled = player(null, true); + cancelled.current = lobby; + cancelled.preConnect = target -> null; + router.enqueueFromInvite(cancelled.player, "beta"); + Fakes.await("cancelled: told", () -> cancelled.said("Couldn't connect you to « beta »")); + assertEq("cancelled: not queued", queued, router.waitingCount()); + assertEq("failed transfers counted", failed + 6, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); + + // A backend that kicks the login says why; "please try again" is wrong for a ban, + // and so is dialling again. Fakes.FakePlayer full = player(null, true); full.current = lobby; full.refusals.put("beta", "The server is full"); router.enqueueFromInvite(full.player, "beta"); Fakes.await("refused transfer: told the reason", () -> full.said("Couldn't connect you to « beta ». Reason: The server is full")); - assertEq("refused transfer counted", 2L, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); + assertEq("refused transfer counted", failed + 7, plugin.stats().total(ProxyStats.Event.TRANSFER_FAILED)); assertEq("refused transfer: no retry advice", false, full.said("try again")); + assertEq("refused transfer: not queued", queued, router.waitingCount()); + router.tick(); + assertEq("refused transfer: dialled once", 1, full.connects.size()); } // /felis lobby and /felis go lobby: the lobby is a system server, so it never @@ -641,6 +704,15 @@ public final class WaitingRouterTest { full.refusals.put("lobby", "Server is full"); router.toLobby(full.player); Fakes.await("lobby refused: told", () -> full.said("Couldn't connect you to « lobby ». Reason: Server is full")); + + // The lobby gets one dial: it is no queue target, and the player can ask again. + Fakes.FakePlayer cut = player(null, true); + cut.current = beta; + cut.connectThrows = true; + int queued = router.waitingCount(); + router.toLobby(cut.player); + assertEq("lobby unreachable: told", true, cut.said("Couldn't connect you to « lobby ». Please try again.")); + assertEq("lobby unreachable: not queued", queued, router.waitingCount()); } private static void disconnectAndRelease() {