Changed link monitoring as described by on4kst, Alain

This commit is contained in:
Marc Froehlich
2026-09-13 19:50:33 +02:00
parent f0508f51a2
commit 393c9c49ee
8 changed files with 1028 additions and 90 deletions
+5 -5
View File
@@ -1,6 +1,6 @@
# KST4Contest Project Context # KST4Contest Project Context
Last reviewed: 2026-09-12 Last reviewed: 2026-09-13
This file is the durable technical project context for KST4Contest. It is not a user manual and not a replacement for the changelog. Current code, tests and authoritative external specifications remain the source of truth when this document is stale or ambiguous. This file is the durable technical project context for KST4Contest. It is not a user manual and not a replacement for the changelog. Current code, tests and authoritative external specifications remain the source of truth when this document is stale or ambiguous.
@@ -126,11 +126,11 @@ CR/LF framing, XML framing, ports/transports, callsign normalization and frequen
### ON4KST session liveness ### ON4KST session liveness
- After 90 seconds without inbound data, the application keeps the established empty CRLF heartbeat. - Only after the session is fully authenticated and synchronized, more than 90 seconds without inbound server data trigger one client-side `CK|\r\n` liveness probe. The trailing pipe matches the framing used by the server for its own `CK|\r\n` probe. The probe state belongs to the TCP session, so a two-category session still sends only one probe per idle phase.
- At about 180 seconds of inbound idle time, the TCP session sends one `RDXQ|<main chat id>|` probe. The probe state belongs to the session, so a two-category session still sends only one probe per idle phase. - The live ON4KST test returned `OK|\r\n` for `CK|\r\n`. KST4Contest treats both that confirmed frame and the originally specified `OK\r\n` form as internal responses: it records inbound activity, confirms the outstanding probe and does not publish the response as chat content. Any other inbound server frame also confirms reachability and starts a new idle phase.
- Any subsequent inbound server frame confirms the probe. `DXQ` is accepted as the expected internal response and is not published as chat content. - A `CK` initiated by the server remains a separate protocol case and receives the established empty CRLF response. It must not be confused with the client-side probe.
- If no inbound frame arrives by about 210 seconds, the existing reconnect flow remains responsible for replacing the session. - If no inbound frame arrives by about 210 seconds, the existing reconnect flow remains responsible for replacing the session.
- Probe diagnostics contain the session id, main category, opcode and timing only. They must not include credentials, complete server frames or normal chat messages. - Liveness diagnostics contain the session id, opcode and timing only. They must not include credentials, complete server frames or normal chat messages.
## User Workflow / UI Invariants ## User Workflow / UI Invariants
@@ -877,10 +877,9 @@ public class MessageBusManagementThread extends Thread {
|| messageToProcess.getMessageText().isEmpty()) { || messageToProcess.getMessageText().isEmpty()) {
// No processable data. // No processable data.
} else { } else {
if (On4KstProtocol.isConnectionProbeResponse( if (On4KstProtocol.isInternalDxqResponse(
messageToProcess.getMessageText())) { messageToProcess.getMessageText())) {
// DXQ is the internal response to the active connection probe. // Preserve the established internal handling of DXQ server data.
// Liveness was already recorded by the session manager.
return; return;
} }
@@ -2183,7 +2182,7 @@ public class MessageBusManagementThread extends Thread {
// e.printStackTrace(); // e.printStackTrace();
// } // }
if (!On4KstProtocol.isConnectionProbeResponse( if (!On4KstProtocol.isInternalDxqResponse(
messageTextRaw.getMessageText())) { messageTextRaw.getMessageText())) {
System.out.println(messageTextRaw.getMessageText() + " <- RXed"); // Stdout at System.out.println(messageTextRaw.getMessageText() + " <- RXed"); // Stdout at
// Console#######################################################TODO:Wichtig // Console#######################################################TODO:Wichtig
@@ -47,9 +47,7 @@ final class On4KstConnectionManager {
static final int CONNECT_TIMEOUT_MILLIS = 10_000; //TCP-Connect-Timeout static final int CONNECT_TIMEOUT_MILLIS = 10_000; //TCP-Connect-Timeout
static final long LOGIN_FALLBACK_MILLIS = 2_000L; //Login-Fallback static final long LOGIN_FALLBACK_MILLIS = 2_000L; //Login-Fallback
static final long HANDSHAKE_TIMEOUT_MILLIS = 45_000L; //Handshake-Timeout static final long HANDSHAKE_TIMEOUT_MILLIS = 45_000L; //Handshake-Timeout
static final long APPLICATION_HEARTBEAT_AFTER_MILLIS = 90_000L; //Application-Heartbeat static final long CLIENT_LIVENESS_PROBE_AFTER_MILLIS = 90_000L;
/** Idle duration after which the server is asked for current DX data. */
static final long CONNECTION_PROBE_AFTER_MILLIS = 180_000L; //Active connection probe
static final long INBOUND_STALE_AFTER_MILLIS = 210_000L; //Stale-Timeout - time without rxed data static final long INBOUND_STALE_AFTER_MILLIS = 210_000L; //Stale-Timeout - time without rxed data
static final List<Long> RECONNECT_DELAYS_MILLIS = static final List<Long> RECONNECT_DELAYS_MILLIS =
List.of(2_000L, 5_000L, 10_000L, 20_000L, 30_000L); //Reconnect-Backoff if no connection possible List.of(2_000L, 5_000L, 10_000L, 20_000L, 30_000L); //Reconnect-Backoff if no connection possible
@@ -181,10 +179,10 @@ final class On4KstConnectionManager {
session.lastProgressMillis.set(now); session.lastProgressMillis.set(now);
String opcode = On4KstProtocol.opcode(line); String opcode = On4KstProtocol.opcode(line);
long probeResponseMillis = session.connectionProbe.acknowledge(now); long probeResponseMillis = session.clientLivenessProbe.acknowledge(now);
if (probeResponseMillis >= 0L) { if (probeResponseMillis >= 0L) {
LOGGER.log(Level.INFO, LOGGER.log(Level.INFO,
"ON4KST connection probe confirmed: session {0}, " "ON4KST client liveness probe confirmed: session {0}, "
+ "received opcode {1}, response time {2} ms", + "received opcode {1}, response time {2} ms",
new Object[] { new Object[] {
sessionId, sessionId,
@@ -193,8 +191,8 @@ final class On4KstConnectionManager {
}); });
} }
if ("CK".equals(opcode)) { if (On4KstProtocol.isServerLivenessProbe(line)) {
sendHeartbeat(session); sendServerLivenessProbeResponse(session);
} }
if (!session.loginSent if (!session.loginSent
@@ -265,8 +263,7 @@ final class On4KstConnectionManager {
token, token,
socket, socket,
receiveQueue, receiveQueue,
transmitQueue, transmitQueue);
mainCategory);
ReadThread readThread = new ReadThread( ReadThread readThread = new ReadThread(
token, socket, receiveQueue, this::isActiveSession, token, socket, receiveQueue, this::isActiveSession,
@@ -541,42 +538,35 @@ final class On4KstConnectionManager {
session.transmitQueue.offer(message); session.transmitQueue.offer(message);
} }
private void sendHeartbeat(Session session) { private void sendServerLivenessProbeResponse(Session session) {
if (session == null || !isActiveSession(session.id)) { if (session == null || !isActiveSession(session.id)) {
return; return;
} }
long now = System.currentTimeMillis();
session.lastHeartbeatMillis.set(now);
LOGGER.log(Level.FINE, LOGGER.log(Level.FINE,
"Sending application heartbeat for ON4KST session {0}", "Responding to ON4KST server liveness probe: session {0}, "
+ "opcode CK",
session.id); session.id);
ChatMessage heartbeat = new ChatMessage(); sendControl(session, On4KstProtocol.serverLivenessProbeResponse());
heartbeat.setMessageDirectedToServer(true);
heartbeat.setMessageText("");
session.transmitQueue.offer(heartbeat);
} }
private void sendConnectionProbe( private void sendClientLivenessProbe(
Session session, Session session,
long now, long now,
long inboundIdle long inboundIdle
) { ) {
if (session == null || !isActiveSession(session.id) if (session == null || !isActiveSession(session.id)
|| !session.connectionProbe.tryStart(now)) { || !session.clientLivenessProbe.tryStart(now)) {
return; return;
} }
LOGGER.log(Level.INFO, LOGGER.log(Level.INFO,
"Sending ON4KST connection probe: session {0}, main category " "Sending ON4KST client liveness probe: session {0}, "
+ "{1}, inbound idle {2} seconds", + "opcode CK, inbound idle {1} seconds",
new Object[] { new Object[] {
session.id, session.id,
session.mainCategory,
inboundIdle / 1_000L inboundIdle / 1_000L
}); });
sendControl( sendControl(session, On4KstProtocol.clientLivenessProbe());
session,
On4KstProtocol.connectionProbe(session.mainCategory));
} }
private void onConnectionFailure(long sessionId, Throwable failure) { private void onConnectionFailure(long sessionId, Throwable failure) {
@@ -682,8 +672,8 @@ final class On4KstConnectionManager {
long inboundIdle = now - lastInboundMillis; long inboundIdle = now - lastInboundMillis;
IdleAction idleAction = determineIdleAction( IdleAction idleAction = determineIdleAction(
inboundIdle, inboundIdle,
session.lastHeartbeatMillis.get() >= lastInboundMillis, session.online,
session.connectionProbe.isOutstanding()); session.clientLivenessProbe.isOutstanding());
if (session.lastInboundMillis.get() != lastInboundMillis) { if (session.lastInboundMillis.get() != lastInboundMillis) {
return; return;
@@ -695,16 +685,15 @@ final class On4KstConnectionManager {
return; return;
} }
long probeWaitMillis = long probeWaitMillis =
session.connectionProbe.responseWaitMillis(now); session.clientLivenessProbe.responseWaitMillis(now);
if (probeWaitMillis >= 0L) { if (probeWaitMillis >= 0L) {
LOGGER.log(Level.WARNING, LOGGER.log(Level.WARNING,
"ON4KST connection probe timed out: session " "ON4KST client liveness probe timed out: "
+ "{0}, main category {1}, no response " + "session {0}, opcode CK, no response "
+ "for {2} ms, inbound idle {3} seconds; " + "for {1} ms, inbound idle {2} seconds; "
+ "reconnecting", + "reconnecting",
new Object[] { new Object[] {
session.id, session.id,
session.mainCategory,
probeWaitMillis, probeWaitMillis,
inboundIdle / 1_000L inboundIdle / 1_000L
}); });
@@ -713,9 +702,8 @@ final class On4KstConnectionManager {
new SocketException("No ON4KST data received for " new SocketException("No ON4KST data received for "
+ inboundIdle / 1_000L + " seconds")); + inboundIdle / 1_000L + " seconds"));
} }
case CONNECTION_PROBE -> case CLIENT_LIVENESS_PROBE ->
sendConnectionProbe(session, now, inboundIdle); sendClientLivenessProbe(session, now, inboundIdle);
case HEARTBEAT -> sendHeartbeat(session);
case NONE -> { case NONE -> {
// The session is active or already has the required idle action. // The session is active or already has the required idle action.
} }
@@ -731,19 +719,18 @@ final class On4KstConnectionManager {
*/ */
static IdleAction determineIdleAction( static IdleAction determineIdleAction(
long inboundIdleMillis, long inboundIdleMillis,
boolean heartbeatSentForIdlePhase, boolean online,
boolean probeOutstanding boolean probeOutstanding
) { ) {
if (!online) {
return IdleAction.NONE;
}
if (inboundIdleMillis > INBOUND_STALE_AFTER_MILLIS) { if (inboundIdleMillis > INBOUND_STALE_AFTER_MILLIS) {
return IdleAction.TIMEOUT; return IdleAction.TIMEOUT;
} }
if (inboundIdleMillis >= CONNECTION_PROBE_AFTER_MILLIS if (inboundIdleMillis > CLIENT_LIVENESS_PROBE_AFTER_MILLIS
&& !probeOutstanding) { && !probeOutstanding) {
return IdleAction.CONNECTION_PROBE; return IdleAction.CLIENT_LIVENESS_PROBE;
}
if (inboundIdleMillis > APPLICATION_HEARTBEAT_AFTER_MILLIS
&& !heartbeatSentForIdlePhase) {
return IdleAction.HEARTBEAT;
} }
return IdleAction.NONE; return IdleAction.NONE;
} }
@@ -894,15 +881,13 @@ final class On4KstConnectionManager {
private final Socket socket; private final Socket socket;
private final LinkedBlockingQueue<ChatMessage> receiveQueue; private final LinkedBlockingQueue<ChatMessage> receiveQueue;
private final LinkedBlockingQueue<ChatMessage> transmitQueue; private final LinkedBlockingQueue<ChatMessage> transmitQueue;
private final int mainCategory;
private final long connectedMillis = System.currentTimeMillis(); private final long connectedMillis = System.currentTimeMillis();
private final AtomicLong lastInboundMillis = private final AtomicLong lastInboundMillis =
new AtomicLong(connectedMillis); new AtomicLong(connectedMillis);
private final AtomicLong lastProgressMillis = private final AtomicLong lastProgressMillis =
new AtomicLong(connectedMillis); new AtomicLong(connectedMillis);
private final AtomicLong lastHeartbeatMillis = new AtomicLong(); private final ClientLivenessProbeState clientLivenessProbe =
private final ConnectionProbeState connectionProbe = new ClientLivenessProbeState();
new ConnectionProbeState();
private final Map<Integer, Map<String, ChatMember>> initialMembers = private final Map<Integer, Map<String, ChatMember>> initialMembers =
new ConcurrentHashMap<>(); new ConcurrentHashMap<>();
@@ -920,27 +905,24 @@ final class On4KstConnectionManager {
long id, long id,
Socket socket, Socket socket,
LinkedBlockingQueue<ChatMessage> receiveQueue, LinkedBlockingQueue<ChatMessage> receiveQueue,
LinkedBlockingQueue<ChatMessage> transmitQueue, LinkedBlockingQueue<ChatMessage> transmitQueue
int mainCategory
) { ) {
this.id = id; this.id = id;
this.socket = socket; this.socket = socket;
this.receiveQueue = receiveQueue; this.receiveQueue = receiveQueue;
this.transmitQueue = transmitQueue; this.transmitQueue = transmitQueue;
this.mainCategory = mainCategory;
} }
} }
/** Maintenance action selected by the session monitor. */ /** Maintenance action selected by the session monitor. */
enum IdleAction { enum IdleAction {
NONE, NONE,
HEARTBEAT, CLIENT_LIVENESS_PROBE,
CONNECTION_PROBE,
TIMEOUT TIMEOUT
} }
/** Tracks one outstanding liveness probe for the complete TCP session. */ /** Tracks one client-initiated liveness probe for the complete TCP session. */
static final class ConnectionProbeState { static final class ClientLivenessProbeState {
private final AtomicLong sentMillis = new AtomicLong(); private final AtomicLong sentMillis = new AtomicLong();
boolean tryStart(long now) { boolean tryStart(long now) {
@@ -54,13 +54,32 @@ final class On4KstProtocol {
+ "|0|"; + "|0|";
} }
/** Builds the active liveness probe for the session's main chat. */ /** Builds the session-wide liveness probe initiated by this client. */
static String connectionProbe(int category) { static String clientLivenessProbe() {
return "RDXQ|" + category(category) + "|"; return "CK|";
} }
/** Returns whether a server frame is the expected liveness-probe response. */ /** Returns whether a server frame acknowledges a client-initiated probe. */
static boolean isConnectionProbeResponse(String frame) { static boolean isClientLivenessProbeResponse(String frame) {
if (frame == null) {
return false;
}
String normalized = frame.trim().toUpperCase(Locale.ROOT);
return "OK".equals(normalized) || "OK|".equals(normalized);
}
/** Returns whether ON4KST initiated its own liveness check. */
static boolean isServerLivenessProbe(String frame) {
return "CK".equals(opcode(frame));
}
/** Builds the established empty response to a server-initiated {@code CK}. */
static String serverLivenessProbeResponse() {
return "";
}
/** Preserves the existing internal handling of DXQ server data. */
static boolean isInternalDxqResponse(String frame) {
return "DXQ".equals(opcode(frame)); return "DXQ".equals(opcode(frame));
} }
@@ -86,11 +86,20 @@ public class ReadThread extends Thread {
throw new EOFException("ON4KST closed the TCP connection"); throw new EOFException("ON4KST closed the TCP connection");
} }
if (!sessionIsActive.test(sessionId)) {
break;
}
inboundActivity.accept(response); inboundActivity.accept(response);
if (!sessionIsActive.test(sessionId)) { if (!sessionIsActive.test(sessionId)) {
break; break;
} }
if (On4KstProtocol.isClientLivenessProbeResponse(response)) {
// OK and OK| acknowledge the client-side CK| probe.
continue;
}
ChatMessage message = new ChatMessage(); ChatMessage message = new ChatMessage();
message.setMessageText(response); message.setMessageText(response);
receiveQueue.put(message); receiveQueue.put(message);
@@ -3,46 +3,63 @@ package kst4contest.controller;
import static org.junit.jupiter.api.Assertions.assertArrayEquals; import static org.junit.jupiter.api.Assertions.assertArrayEquals;
import static org.junit.jupiter.api.Assertions.assertEquals; import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertFalse; import static org.junit.jupiter.api.Assertions.assertFalse;
import static org.junit.jupiter.api.Assertions.assertNull;
import static org.junit.jupiter.api.Assertions.assertTrue; import static org.junit.jupiter.api.Assertions.assertTrue;
import java.io.OutputStreamWriter;
import java.lang.reflect.Field;
import java.net.ServerSocket; import java.net.ServerSocket;
import java.net.Socket; import java.net.Socket;
import java.nio.charset.StandardCharsets; import java.nio.charset.StandardCharsets;
import java.time.Duration; import java.time.Duration;
import java.util.concurrent.CompletableFuture; import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.LinkedBlockingQueue; import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicLong;
import org.junit.jupiter.api.Test; import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.Timeout; import org.junit.jupiter.api.Timeout;
import kst4contest.model.ChatCategory;
import kst4contest.model.ChatMessage; import kst4contest.model.ChatMessage;
import kst4contest.model.ChatPreferences;
class On4KstConnectionProbeTest { class On4KstConnectionProbeTest {
@Test @Test
void buildsMainChatProbeAndAcceptsExpectedResponse() { void separatesClientProbeServerProbeAndInternalResponses() {
assertEquals("RDXQ|2|", On4KstProtocol.connectionProbe(2)); assertEquals("CK|", On4KstProtocol.clientLivenessProbe());
assertTrue(On4KstProtocol.isConnectionProbeResponse("DXQ|2|data|")); assertTrue(On4KstProtocol.isClientLivenessProbeResponse("OK"));
assertFalse(On4KstProtocol.isConnectionProbeResponse( assertTrue(On4KstProtocol.isClientLivenessProbeResponse("OK|"));
"CH|2|123|DL1ABC|Name|0|text|0|")); assertFalse(On4KstProtocol.isClientLivenessProbeResponse(
"OK|unexpected|"));
assertTrue(On4KstProtocol.isServerLivenessProbe("CK|"));
assertEquals("", On4KstProtocol.serverLivenessProbeResponse());
assertTrue(On4KstProtocol.isInternalDxqResponse("DXQ|2|data|"));
} }
@Test @Test
void selectsHeartbeatProbeAndTimeoutAtIdleBoundaries() { void selectsOneClientProbeAndTimeoutAtIdleBoundaries() {
assertEquals( assertEquals(
On4KstConnectionManager.IdleAction.NONE, On4KstConnectionManager.IdleAction.NONE,
idleAction(90_000L, false, false)); idleAction(90_000L, true, false));
assertEquals(
On4KstConnectionManager.IdleAction.HEARTBEAT,
idleAction(90_001L, false, false));
assertEquals( assertEquals(
On4KstConnectionManager.IdleAction.NONE, On4KstConnectionManager.IdleAction.NONE,
idleAction(179_999L, true, false)); idleAction(90_001L, false, false),
"No client probe may be sent before the session is online");
assertEquals( assertEquals(
On4KstConnectionManager.IdleAction.CONNECTION_PROBE, On4KstConnectionManager.IdleAction.CLIENT_LIVENESS_PROBE,
idleAction(180_000L, true, false)); idleAction(90_001L, true, false));
assertEquals(
On4KstConnectionManager.IdleAction.NONE,
idleAction(180_000L, true, true),
"The 90-second CK remains the only probe in this idle phase");
assertEquals(
On4KstConnectionManager.IdleAction.CLIENT_LIVENESS_PROBE,
idleAction(180_000L, true, false),
"Even without probe state, the only 180-second action is CK");
assertEquals( assertEquals(
On4KstConnectionManager.IdleAction.NONE, On4KstConnectionManager.IdleAction.NONE,
idleAction(210_000L, true, true)); idleAction(210_000L, true, true));
@@ -52,9 +69,9 @@ class On4KstConnectionProbeTest {
} }
@Test @Test
void oneSessionProbeIsAcknowledgedByAnyInboundTraffic() { void sessionProbeCoversTwoCategoriesAndRepeatedIdlePhases() {
On4KstConnectionManager.ConnectionProbeState probe = On4KstConnectionManager.ClientLivenessProbeState probe =
new On4KstConnectionManager.ConnectionProbeState(); new On4KstConnectionManager.ClientLivenessProbeState();
assertTrue(probe.tryStart(1_000L)); assertTrue(probe.tryStart(1_000L));
assertFalse(probe.tryStart(1_001L), assertFalse(probe.tryStart(1_001L),
@@ -71,8 +88,8 @@ class On4KstConnectionProbeTest {
@Test @Test
@Timeout(5) @Timeout(5)
void writerUsesExactCrLfForHeartbeatAndConnectionProbe() throws Exception { void writerUsesExactBytesForClientAndServerLivenessFrames() throws Exception {
byte[] expected = "\r\nRDXQ|2|\r\n".getBytes(StandardCharsets.UTF_8); byte[] expected = "CK|\r\n\r\n".getBytes(StandardCharsets.UTF_8);
try (ServerSocket server = new ServerSocket(0)) { try (ServerSocket server = new ServerSocket(0)) {
CompletableFuture<byte[]> received = CompletableFuture.supplyAsync(() -> { CompletableFuture<byte[]> received = CompletableFuture.supplyAsync(() -> {
@@ -98,8 +115,9 @@ class On4KstConnectionProbeTest {
ignored -> { }); ignored -> { });
writer.start(); writer.start();
queue.add(serverFrame("")); queue.add(serverFrame(On4KstProtocol.clientLivenessProbe()));
queue.add(serverFrame(On4KstProtocol.connectionProbe(2))); queue.add(serverFrame(
On4KstProtocol.serverLivenessProbeResponse()));
assertArrayEquals( assertArrayEquals(
expected, expected,
@@ -112,14 +130,153 @@ class On4KstConnectionProbeTest {
} }
} }
@Test
@Timeout(5)
void readerRecordsOkAsActivityWithoutPublishingIt() throws Exception {
CountDownLatch releaseChatFrame = new CountDownLatch(1);
String chatFrame = "CH|2|123|DL1ABC|Name|0|text|0|";
try (ServerSocket server = new ServerSocket(0)) {
CompletableFuture<Void> serverDone = CompletableFuture.runAsync(() -> {
try (Socket accepted = server.accept();
OutputStreamWriter out = new OutputStreamWriter(
accepted.getOutputStream(), StandardCharsets.UTF_8)) {
out.write("OK|\r\n");
out.flush();
releaseChatFrame.await(2, TimeUnit.SECONDS);
out.write(chatFrame + "\r\n");
out.flush();
} catch (Exception exception) {
throw new RuntimeException(exception);
}
});
try (Socket client = new Socket("127.0.0.1", server.getLocalPort())) {
LinkedBlockingQueue<ChatMessage> messages =
new LinkedBlockingQueue<>();
LinkedBlockingQueue<String> activity =
new LinkedBlockingQueue<>();
AtomicBoolean active = new AtomicBoolean(true);
ReadThread reader = new ReadThread(
21L,
client,
messages,
ignored -> active.get(),
activity::offer,
ignored -> { });
reader.start();
assertEquals("OK|", activity.poll(2, TimeUnit.SECONDS));
assertNull(messages.poll(200, TimeUnit.MILLISECONDS));
releaseChatFrame.countDown();
assertEquals(chatFrame,
messages.poll(2, TimeUnit.SECONDS).getMessageText());
active.set(false);
reader.join(Duration.ofSeconds(2).toMillis());
}
serverDone.get(2, TimeUnit.SECONDS);
}
}
@Test
@Timeout(5)
void readerIgnoresDelayedResponseFromReplacedSession() throws Exception {
CountDownLatch releaseOldResponse = new CountDownLatch(1);
AtomicBoolean inboundCallbackUsed = new AtomicBoolean();
try (ServerSocket server = new ServerSocket(0)) {
CompletableFuture<Void> serverDone = CompletableFuture.runAsync(() -> {
try (Socket accepted = server.accept();
OutputStreamWriter out = new OutputStreamWriter(
accepted.getOutputStream(), StandardCharsets.UTF_8)) {
releaseOldResponse.await(2, TimeUnit.SECONDS);
out.write("OK\r\n");
out.flush();
} catch (Exception exception) {
throw new RuntimeException(exception);
}
});
try (Socket client = new Socket("127.0.0.1", server.getLocalPort())) {
LinkedBlockingQueue<ChatMessage> messages =
new LinkedBlockingQueue<>();
AtomicBoolean active = new AtomicBoolean(true);
ReadThread reader = new ReadThread(
22L,
client,
messages,
ignored -> active.get(),
ignored -> inboundCallbackUsed.set(true),
ignored -> { });
reader.start();
active.set(false);
releaseOldResponse.countDown();
reader.join(Duration.ofSeconds(2).toMillis());
assertFalse(inboundCallbackUsed.get());
assertNull(messages.poll());
}
serverDone.get(2, TimeUnit.SECONDS);
}
}
@Test
@Timeout(15)
void unansweredProbeUsesExistingReconnectFlow() throws Exception {
ChatPreferences preferences = localPreferences();
ChatController controller = org.mockito.Mockito.mock(
ChatController.class);
org.mockito.Mockito.when(controller.getChatPreferences())
.thenReturn(preferences);
org.mockito.Mockito.when(controller.getChatCategoryMain())
.thenReturn(preferences.getLoginChatCategoryMain());
org.mockito.Mockito.when(controller.getChatCategorySecondChat())
.thenReturn(preferences.getLoginChatCategorySecond());
try (ServerSocket server = new ServerSocket(0)) {
preferences.setStn_on4kstServersPort(server.getLocalPort());
CompletableFuture<Integer> acceptedConnections =
CompletableFuture.supplyAsync(() -> {
try (Socket first = server.accept();
Socket second = server.accept()) {
return 2;
} catch (Exception exception) {
throw new RuntimeException(exception);
}
});
On4KstConnectionManager manager =
new On4KstConnectionManager(controller);
try {
manager.start();
awaitState(manager, On4KstConnectionState.AUTHENTICATING);
manager.onLogstat(1L, new String[] {"LOGSTAT", "100"});
awaitState(manager, On4KstConnectionState.SYNCING_MAIN_CHAT);
manager.onInitialUserListCompleted(1L,
preferences.getLoginChatCategoryMain());
awaitState(manager, On4KstConnectionState.ONLINE);
setTimedOutProbe(manager, System.currentTimeMillis());
awaitState(manager, On4KstConnectionState.RECONNECT_WAIT);
assertEquals(2, acceptedConnections.get(7, TimeUnit.SECONDS));
} finally {
manager.stopByUser();
}
}
}
private On4KstConnectionManager.IdleAction idleAction( private On4KstConnectionManager.IdleAction idleAction(
long inboundIdleMillis, long inboundIdleMillis,
boolean heartbeatSent, boolean online,
boolean probeOutstanding boolean probeOutstanding
) { ) {
return On4KstConnectionManager.determineIdleAction( return On4KstConnectionManager.determineIdleAction(
inboundIdleMillis, inboundIdleMillis,
heartbeatSent, online,
probeOutstanding); probeOutstanding);
} }
@@ -129,4 +286,55 @@ class On4KstConnectionProbeTest {
message.setMessageText(text); message.setMessageText(text);
return message; return message;
} }
private ChatPreferences localPreferences() {
ChatPreferences preferences = new ChatPreferences();
preferences.setStn_on4kstServersDns("127.0.0.1");
preferences.setStn_loginCallSign("DL1ABC");
preferences.setStn_loginPassword("test-password");
preferences.setStn_loginNameMainCat("");
preferences.setStn_loginLocatorMainCat("JO50AA");
preferences.setLoginChatCategoryMain(new ChatCategory(2));
preferences.setLoginChatCategorySecond(new ChatCategory(3));
preferences.setLoginToSecondChatEnabled(false);
return preferences;
}
private void awaitState(
On4KstConnectionManager manager,
On4KstConnectionState expected
) throws InterruptedException {
long deadline = System.nanoTime() + TimeUnit.SECONDS.toNanos(7L);
while (System.nanoTime() < deadline) {
if (manager.getState() == expected) {
return;
}
TimeUnit.MILLISECONDS.sleep(25L);
}
assertEquals(expected, manager.getState());
}
private void setTimedOutProbe(
On4KstConnectionManager manager,
long now
) throws ReflectiveOperationException {
Field activeSession = On4KstConnectionManager.class
.getDeclaredField("activeSession");
activeSession.setAccessible(true);
Object session = activeSession.get(manager);
Field lastInboundMillis = session.getClass()
.getDeclaredField("lastInboundMillis");
lastInboundMillis.setAccessible(true);
((AtomicLong) lastInboundMillis.get(session)).set(
now - On4KstConnectionManager.INBOUND_STALE_AFTER_MILLIS - 1L);
Field clientLivenessProbe = session.getClass()
.getDeclaredField("clientLivenessProbe");
clientLivenessProbe.setAccessible(true);
((On4KstConnectionManager.ClientLivenessProbeState)
clientLivenessProbe.get(session)).tryStart(
now - On4KstConnectionManager
.CLIENT_LIVENESS_PROBE_AFTER_MILLIS);
}
} }
@@ -0,0 +1,296 @@
package kst4contest.controller;
import static org.junit.jupiter.api.Assertions.fail;
import static org.junit.jupiter.api.Assumptions.assumeTrue;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.anyBoolean;
import static org.mockito.ArgumentMatchers.anyLong;
import static org.mockito.ArgumentMatchers.anyString;
import static org.mockito.Mockito.doAnswer;
import static org.mockito.Mockito.doNothing;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;
import java.time.Duration;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicReference;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.Timeout;
import kst4contest.model.ChatCategory;
import kst4contest.model.ChatMember;
import kst4contest.model.ChatPreferences;
/**
* Opt-in practice test against the configured ON4KST server.
*
* <p>The normal test suite skips this class. Run it explicitly with
* {@code -Don4kst.live=true -Dtest=On4KstIdlePracticeTest} from the IDE or
* Maven when the locally stored test credentials may be used. The practice
* connection uses only the usually quiet category 9.</p>
*/
class On4KstIdlePracticeTest {
private static final int LIVE_CATEGORY = ChatCategory.VUHFR3;
private static final Duration ONLINE_TIMEOUT = Duration.ofSeconds(90);
private static final Duration QUIET_PHASE_TIMEOUT = Duration.ofMinutes(45);
private static final Duration POST_RESPONSE_OBSERVATION = Duration.ofSeconds(135);
@Test
@Timeout(value = 50, unit = TimeUnit.MINUTES)
void observesCkOkWithoutQuietReconnect() throws Exception {
assumeTrue(Boolean.getBoolean("on4kst.live"),
"Live ON4KST test requires -Don4kst.live=true");
ChatPreferences preferences = new ChatPreferences();
assumeTrue(preferences.readPreferencesFromXmlFile(),
"No readable local ON4KST test configuration");
assumeTrue(hasText(preferences.getStn_loginCallSign())
&& hasText(preferences.getStn_loginPassword()),
"Local ON4KST test credentials are incomplete");
preferences.setLoginChatCategoryMain(
new ChatCategory(LIVE_CATEGORY));
preferences.setLoginToSecondChatEnabled(false);
LinkedBlockingQueue<StateEvent> stateEvents =
new LinkedBlockingQueue<>();
LinkedBlockingQueue<ProbeEvent> probeEvents =
new LinkedBlockingQueue<>();
AtomicBoolean reconnectObserved = new AtomicBoolean();
AtomicReference<On4KstConnectionManager> managerReference =
new AtomicReference<>();
ChatController controller = mock(ChatController.class);
when(controller.getChatPreferences()).thenReturn(preferences);
ChatCategory mainCategory = preferences.getLoginChatCategoryMain();
ChatCategory secondCategory = preferences.getLoginChatCategorySecond();
if (secondCategory == null) {
secondCategory = new ChatCategory(
mainCategory.getCategoryNumber() == 2 ? 3 : 2);
}
when(controller.getChatCategoryMain()).thenReturn(mainCategory);
when(controller.getChatCategorySecondChat()).thenReturn(secondCategory);
DBController database = mock(DBController.class);
when(database.fetchChatMemberWkdDataForOnlyOneCallsignFromDB(
any(ChatMember.class)))
.thenAnswer(invocation -> invocation.getArgument(0));
doNothing().when(database).storeChatMember(any(ChatMember.class));
when(controller.getDbHandler()).thenReturn(database);
doAnswer(invocation -> {
On4KstConnectionState state = invocation.getArgument(0);
stateEvents.offer(new StateEvent(state, ZonedDateTime.now()));
if (state == On4KstConnectionState.RECONNECT_WAIT) {
reconnectObserved.set(true);
}
return null;
}).when(controller).updateOn4KstConnectionState(
any(On4KstConnectionState.class), anyString(), anyBoolean());
doAnswer(invocation -> {
managerReference.get().onLogstat(
invocation.getArgument(0), invocation.getArgument(1));
return null;
}).when(controller).onOn4KstLogstat(anyLong(), any(String[].class));
doAnswer(invocation -> {
managerReference.get().stageInitialChatMember(
invocation.getArgument(0), invocation.getArgument(1));
return null;
}).when(controller).stageInitialOn4KstChatMember(
anyLong(), any(ChatMember.class));
doAnswer(invocation -> {
managerReference.get().onInitialUserListCompleted(
invocation.getArgument(0), invocation.getArgument(1));
return null;
}).when(controller).onOn4KstInitialUserListCompleted(
anyLong(), any(ChatCategory.class));
On4KstConnectionManager manager =
new On4KstConnectionManager(controller);
managerReference.set(manager);
Logger logger = Logger.getLogger(
On4KstConnectionManager.class.getName());
Level previousLevel = logger.getLevel();
Handler probeHandler = probeHandler(probeEvents);
logger.setLevel(Level.INFO);
logger.addHandler(probeHandler);
try {
manager.start();
StateEvent online = awaitOnline(stateEvents);
System.out.println("[ON4KST live] Category " + LIVE_CATEGORY
+ " ONLINE at "
+ timestamp(online.at()));
reconnectObserved.set(false);
ProbeCycle successfulCycle = awaitCkOkCycle(
probeEvents, reconnectObserved);
System.out.println("[ON4KST live] CK sent at "
+ timestamp(successfulCycle.sentAt())
+ ", OK received at "
+ timestamp(successfulCycle.confirmedAt())
+ ", response time "
+ successfulCycle.responseMillis() + " ms");
reconnectObserved.set(false);
long observationDeadline = System.nanoTime()
+ POST_RESPONSE_OBSERVATION.toNanos();
while (System.nanoTime() < observationDeadline) {
if (reconnectObserved.get()) {
fail("ON4KST entered reconnect after the confirmed CK/OK cycle");
}
TimeUnit.SECONDS.sleep(1L);
}
System.out.println("[ON4KST live] Observation completed at "
+ timestamp(ZonedDateTime.now())
+ "; no reconnect followed the quiet CK/OK cycle");
} finally {
manager.stopByUser();
logger.removeHandler(probeHandler);
logger.setLevel(previousLevel);
}
}
private StateEvent awaitOnline(
LinkedBlockingQueue<StateEvent> stateEvents
) throws InterruptedException {
long deadline = System.nanoTime() + ONLINE_TIMEOUT.toNanos();
while (System.nanoTime() < deadline) {
StateEvent event = stateEvents.poll(1L, TimeUnit.SECONDS);
if (event == null) {
continue;
}
if (event.state() == On4KstConnectionState.ONLINE) {
return event;
}
if (event.state() == On4KstConnectionState.DISCONNECTED) {
fail("ON4KST live test disconnected before reaching ONLINE");
}
}
fail("ON4KST live test did not reach ONLINE within "
+ ONLINE_TIMEOUT.toSeconds() + " seconds");
throw new IllegalStateException("unreachable");
}
private ProbeCycle awaitCkOkCycle(
LinkedBlockingQueue<ProbeEvent> probeEvents,
AtomicBoolean reconnectObserved
) throws InterruptedException {
long deadline = System.nanoTime() + QUIET_PHASE_TIMEOUT.toNanos();
ProbeEvent sent = null;
while (System.nanoTime() < deadline) {
if (reconnectObserved.get()) {
fail("ON4KST reconnected before a CK/OK idle cycle was observed");
}
ProbeEvent event = probeEvents.poll(1L, TimeUnit.SECONDS);
if (event == null) {
continue;
}
if (event.type() == ProbeEventType.SENT) {
sent = event;
continue;
}
if (sent != null && event.sessionId() == sent.sessionId()) {
if ("OK".equals(event.opcode())) {
return new ProbeCycle(
sent.at(), event.at(), event.responseMillis());
}
// Normal server data ended this idle phase before OK arrived.
sent = null;
}
}
fail("No uninterrupted CK/OK idle cycle was observed within "
+ QUIET_PHASE_TIMEOUT.toMinutes() + " minutes");
throw new IllegalStateException("unreachable");
}
private Handler probeHandler(
LinkedBlockingQueue<ProbeEvent> probeEvents
) {
return new Handler() {
@Override
public void publish(LogRecord record) {
if (record == null || record.getParameters() == null) {
return;
}
Object[] parameters = record.getParameters();
if (record.getMessage().startsWith(
"Sending ON4KST client liveness probe")
&& parameters.length >= 1) {
probeEvents.offer(new ProbeEvent(
ProbeEventType.SENT,
((Number) parameters[0]).longValue(),
"CK",
-1L,
ZonedDateTime.now()));
} else if (record.getMessage().startsWith(
"ON4KST client liveness probe confirmed")
&& parameters.length >= 3) {
probeEvents.offer(new ProbeEvent(
ProbeEventType.CONFIRMED,
((Number) parameters[0]).longValue(),
String.valueOf(parameters[1]),
((Number) parameters[2]).longValue(),
ZonedDateTime.now()));
}
}
@Override
public void flush() {
// Nothing is buffered.
}
@Override
public void close() {
// The handler owns no external resource.
}
};
}
private boolean hasText(String value) {
return value != null && !value.isBlank();
}
private String timestamp(ZonedDateTime value) {
return DateTimeFormatter.ISO_OFFSET_DATE_TIME.format(value);
}
private record StateEvent(
On4KstConnectionState state,
ZonedDateTime at
) {
}
private enum ProbeEventType {
SENT,
CONFIRMED
}
private record ProbeEvent(
ProbeEventType type,
long sessionId,
String opcode,
long responseMillis,
ZonedDateTime at
) {
}
private record ProbeCycle(
ZonedDateTime sentAt,
ZonedDateTime confirmedAt,
long responseMillis
) {
}
}
@@ -0,0 +1,425 @@
package kst4contest.controller;
import static org.junit.jupiter.api.Assertions.assertTrue;
import static org.junit.jupiter.api.Assumptions.assumeTrue;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.io.Writer;
import java.net.InetSocketAddress;
import java.net.Socket;
import java.net.SocketTimeoutException;
import java.nio.charset.StandardCharsets;
import java.nio.file.Files;
import java.nio.file.Path;
import java.nio.file.StandardOpenOption;
import java.time.Duration;
import java.time.ZonedDateTime;
import java.time.format.DateTimeFormatter;
import java.util.ArrayList;
import java.util.HexFormat;
import java.util.List;
import java.util.concurrent.TimeUnit;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.Timeout;
import kst4contest.ApplicationConstants;
import kst4contest.model.ChatCategory;
import kst4contest.model.ChatPreferences;
/**
* Opt-in raw-wire probe matrix against ON4KST category 9.
*
* <p>Login traffic is deliberately excluded from the evidence file so that no
* credentials or login tokens are persisted. Capture begins after the initial
* category-9 user list has completed.</p>
*/
class On4KstProbeVariantPracticeTest {
private static final int CATEGORY = ChatCategory.VUHFR3;
private static final Duration CONNECT_TIMEOUT = Duration.ofSeconds(10);
private static final Duration HANDSHAKE_TIMEOUT = Duration.ofSeconds(45);
private static final Duration QUIET_PERIOD = Duration.ofSeconds(90);
private static final Duration RESPONSE_TIMEOUT = Duration.ofSeconds(125);
private static final Duration VARIANT_TIMEOUT = Duration.ofMinutes(8);
private static final Duration TOTAL_TIMEOUT = Duration.ofMinutes(45);
private static final List<ProbeVariant> VARIANTS = List.of(
variant("CK_CRLF", "CK\r\n"),
variant("CK_PIPE_CRLF", "CK|\r\n"),
variant("CK_CR_NUL", "CK\r\0"),
variant("CK_PIPE_CR_NUL", "CK|\r\0"),
variant("PIPE_CK_PIPE_CRLF", "|CK|\r\n")
);
@Test
@Timeout(value = 47, unit = TimeUnit.MINUTES)
void recordsProbeVariantResponsesWithoutLoginData() throws Exception {
assumeTrue(Boolean.getBoolean("on4kst.live.variants"),
"Live probe matrix requires -Don4kst.live.variants=true");
ChatPreferences preferences = new ChatPreferences();
assumeTrue(preferences.readPreferencesFromXmlFile(),
"No readable local ON4KST test configuration");
assumeTrue(hasText(preferences.getStn_loginCallSign())
&& hasText(preferences.getStn_loginPassword()),
"Local ON4KST test credentials are incomplete");
Path evidenceDirectory = Path.of(
"target", "on4kst-live-evidence");
Files.createDirectories(evidenceDirectory);
String timestamp = DateTimeFormatter.ofPattern("yyyyMMdd-HHmmss")
.format(ZonedDateTime.now());
Path evidenceFile = evidenceDirectory.resolve(
timestamp + "-category-9-probe-matrix.log");
List<ProbeResult> results = new ArrayList<>();
long totalDeadline = System.nanoTime() + TOTAL_TIMEOUT.toNanos();
try (Writer evidence = Files.newBufferedWriter(
evidenceFile,
StandardCharsets.UTF_8,
StandardOpenOption.CREATE_NEW,
StandardOpenOption.WRITE)) {
writeHeader(evidence);
for (ProbeVariant variant : VARIANTS) {
if (System.nanoTime() >= totalDeadline) {
ProbeResult result = new ProbeResult(
variant.name(), "TOTAL_BUDGET_EXHAUSTED", "");
results.add(result);
writeResult(evidence, result);
continue;
}
ProbeResult result;
try {
result = runVariant(
preferences, variant, totalDeadline, evidence);
} catch (Exception exception) {
result = new ProbeResult(
variant.name(),
"ERROR",
exception.getClass().getSimpleName()
+ ": " + safeMessage(exception));
writeResult(evidence, result);
}
results.add(result);
evidence.flush();
}
evidence.write("\nSUMMARY\n");
for (ProbeResult result : results) {
writeResult(evidence, result);
}
}
System.out.println("[ON4KST variant test] Evidence: "
+ evidenceFile.toAbsolutePath());
assertTrue(
results.stream().anyMatch(result ->
"OK_DIRECT".equals(result.status())),
"No probe variant received a direct OK response. Evidence: "
+ evidenceFile.toAbsolutePath());
}
private ProbeResult runVariant(
ChatPreferences preferences,
ProbeVariant variant,
long totalDeadline,
Writer evidence
) throws Exception {
long variantDeadline = Math.min(
totalDeadline,
System.nanoTime() + VARIANT_TIMEOUT.toNanos());
evidence.write("\nVARIANT " + variant.name() + "\n");
evidence.write("probe hex=" + HexFormat.ofDelimiter(" ")
.withUpperCase().formatHex(variant.bytes())
+ " ascii=" + escapedAscii(variant.bytes()) + "\n");
try (Socket socket = new Socket()) {
socket.connect(
new InetSocketAddress(
preferences.getStn_on4kstServersDns(),
preferences.getStn_on4kstServersPort()),
Math.toIntExact(CONNECT_TIMEOUT.toMillis()));
socket.setSoTimeout(1_000);
InputStream input = socket.getInputStream();
OutputStream output = socket.getOutputStream();
WireReader reader = new WireReader(input);
completeHandshake(preferences, reader, output, variantDeadline);
writeEvent(evidence, "STATE", new byte[0],
"category 9 synchronized; login capture suppressed");
long lastInbound = System.nanoTime();
while (System.nanoTime() < variantDeadline) {
long quietDeadline = Math.min(
variantDeadline,
lastInbound + QUIET_PERIOD.toNanos());
byte[] inbound = reader.readFrame(quietDeadline);
if (inbound == null) {
if (System.nanoTime() >= variantDeadline) {
ProbeResult result = new ProbeResult(
variant.name(), "NO_QUIET_PHASE", "");
writeResult(evidence, result);
return result;
}
break;
}
writeEvent(evidence, "RX", inbound, "pre-probe");
lastInbound = System.nanoTime();
if ("CK".equals(On4KstProtocol.opcode(frameText(inbound)))) {
byte[] response = "\r\n".getBytes(StandardCharsets.US_ASCII);
output.write(response);
output.flush();
writeEvent(evidence, "TX", response,
"response to server-initiated CK");
}
}
output.write(variant.bytes());
output.flush();
writeEvent(evidence, "TX", variant.bytes(), "client probe");
long responseDeadline = Math.min(
variantDeadline,
System.nanoTime() + RESPONSE_TIMEOUT.toNanos());
boolean receivedOtherFrame = false;
while (System.nanoTime() < responseDeadline) {
byte[] inbound = reader.readFrame(responseDeadline);
if (inbound == null) {
break;
}
writeEvent(evidence, "RX", inbound, "post-probe");
String text = frameText(inbound);
if (On4KstProtocol.isClientLivenessProbeResponse(text)) {
String status = receivedOtherFrame
? "OK_AFTER_OTHER_DATA"
: "OK_DIRECT";
ProbeResult result = new ProbeResult(
variant.name(), status, escapedAscii(inbound));
writeResult(evidence, result);
return result;
}
receivedOtherFrame = true;
}
ProbeResult result = new ProbeResult(
variant.name(),
receivedOtherFrame ? "OTHER_DATA_ONLY" : "NO_RESPONSE",
"");
writeResult(evidence, result);
return result;
}
}
private void completeHandshake(
ChatPreferences preferences,
WireReader reader,
OutputStream output,
long variantDeadline
) throws Exception {
long handshakeDeadline = Math.min(
variantDeadline,
System.nanoTime() + HANDSHAKE_TIMEOUT.toNanos());
byte[] prompt = requireFrame(reader, handshakeDeadline,
"ON4KST login prompt");
if (!frameText(prompt).toLowerCase().contains("login")) {
throw new IOException("Unexpected ON4KST login prompt opcode: "
+ On4KstProtocol.opcode(frameText(prompt)));
}
String login = On4KstProtocol.login(
preferences.getStn_loginCallSign(),
preferences.getStn_loginPassword(),
CATEGORY,
"KST4Contest v"
+ ApplicationConstants.APPLICATION_CURRENT_VERSION,
0L);
writeCrLfFrame(output, login);
boolean loginAccepted = false;
while (!loginAccepted) {
byte[] inbound = requireFrame(reader, handshakeDeadline,
"ON4KST LOGSTAT");
String text = frameText(inbound);
if (!"LOGSTAT".equals(On4KstProtocol.opcode(text))) {
continue;
}
String[] fields = text.split("\\|", -1);
if (fields.length < 2 || !"100".equals(fields[1])) {
throw new IOException("ON4KST login rejected with code "
+ (fields.length < 2 ? "missing" : fields[1]));
}
loginAccepted = true;
}
writeCrLfFrame(output, On4KstProtocol.settingsDone(CATEGORY));
while (true) {
byte[] inbound = requireFrame(reader, handshakeDeadline,
"category-9 user-list completion");
String text = frameText(inbound);
if (text.startsWith("UE|" + CATEGORY + "|")) {
return;
}
}
}
private byte[] requireFrame(
WireReader reader,
long deadline,
String description
) throws IOException {
byte[] frame = reader.readFrame(deadline);
if (frame == null) {
throw new SocketTimeoutException(
"Timed out waiting for " + description);
}
return frame;
}
private void writeCrLfFrame(OutputStream output, String frame)
throws IOException {
output.write(frame.getBytes(StandardCharsets.US_ASCII));
output.write('\r');
output.write('\n');
output.flush();
}
private void writeHeader(Writer evidence) throws IOException {
evidence.write("ON4KST client-probe wire evidence\n");
evidence.write("started=" + DateTimeFormatter.ISO_OFFSET_DATE_TIME
.format(ZonedDateTime.now()) + "\n");
evidence.write("category=9\n");
evidence.write("login and initial synchronization frames are suppressed"
+ " to exclude credentials and login tokens\n");
evidence.write("wtKST reference: server CK frame="
+ "43 4B 7C 0D 0A (CK|<CR><LF>)\n");
evidence.write("wtKST reference: no client CK and no server OK occur"
+ " in wtkstcomm.c\n");
evidence.write("wtKST reference: repeated client idle payload="
+ "0D 00 0D 0A (<CR><NUL><CR><LF>)\n");
}
private void writeEvent(
Writer evidence,
String direction,
byte[] bytes,
String note
) throws IOException {
evidence.write(DateTimeFormatter.ISO_OFFSET_DATE_TIME
.format(ZonedDateTime.now()));
evidence.write(" " + direction);
if (bytes.length > 0) {
evidence.write(" hex=" + HexFormat.ofDelimiter(" ")
.withUpperCase().formatHex(bytes));
evidence.write(" ascii=" + escapedAscii(bytes));
}
if (hasText(note)) {
evidence.write(" note=" + note);
}
evidence.write("\n");
evidence.flush();
}
private void writeResult(Writer evidence, ProbeResult result)
throws IOException {
evidence.write("RESULT variant=" + result.variant()
+ " status=" + result.status());
if (hasText(result.detail())) {
evidence.write(" detail=" + result.detail());
}
evidence.write("\n");
}
private static ProbeVariant variant(String name, String wireText) {
return new ProbeVariant(
name, wireText.getBytes(StandardCharsets.US_ASCII));
}
private String frameText(byte[] frame) {
int length = frame.length;
while (length > 0 && (frame[length - 1] == '\r'
|| frame[length - 1] == '\n'
|| frame[length - 1] == 0)) {
length--;
}
return new String(frame, 0, length, StandardCharsets.US_ASCII);
}
private String escapedAscii(byte[] bytes) {
StringBuilder escaped = new StringBuilder();
for (byte value : bytes) {
int unsigned = Byte.toUnsignedInt(value);
switch (unsigned) {
case 0 -> escaped.append("<NUL>");
case '\r' -> escaped.append("<CR>");
case '\n' -> escaped.append("<LF>");
default -> {
if (unsigned >= 0x20 && unsigned <= 0x7e) {
escaped.append((char) unsigned);
} else {
escaped.append(String.format("<%02X>", unsigned));
}
}
}
}
return escaped.toString();
}
private String safeMessage(Exception exception) {
String message = exception.getMessage();
return message == null || message.isBlank()
? "no detail" : message.replaceAll("[\\r\\n]+", " ");
}
private boolean hasText(String value) {
return value != null && !value.isBlank();
}
private record ProbeVariant(String name, byte[] bytes) {
private ProbeVariant {
bytes = bytes.clone();
}
@Override
public byte[] bytes() {
return bytes.clone();
}
}
private record ProbeResult(String variant, String status, String detail) {
}
private static final class WireReader {
private final InputStream input;
private WireReader(InputStream input) {
this.input = input;
}
private byte[] readFrame(long deadlineNanos) throws IOException {
ByteArrayOutputStream frame = new ByteArrayOutputStream();
while (System.nanoTime() < deadlineNanos) {
try {
int value = input.read();
if (value < 0) {
throw new IOException("ON4KST closed the TCP session");
}
frame.write(value);
if (value == '\n' || value == 0) {
return frame.toByteArray();
}
} catch (SocketTimeoutException timeout) {
// Continue until the caller's monotonic deadline expires.
}
}
return frame.size() == 0 ? null : frame.toByteArray();
}
}
}