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
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.
@@ -126,11 +126,11 @@ CR/LF framing, XML framing, ports/transports, callsign normalization and frequen
### ON4KST session liveness
- After 90 seconds without inbound data, the application keeps the established empty CRLF heartbeat.
- 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.
- Any subsequent inbound server frame confirms the probe. `DXQ` is accepted as the expected internal response and is not published as chat content.
- 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.
- 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.
- 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.
- 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
@@ -877,10 +877,9 @@ public class MessageBusManagementThread extends Thread {
|| messageToProcess.getMessageText().isEmpty()) {
// No processable data.
} else {
if (On4KstProtocol.isConnectionProbeResponse(
if (On4KstProtocol.isInternalDxqResponse(
messageToProcess.getMessageText())) {
// DXQ is the internal response to the active connection probe.
// Liveness was already recorded by the session manager.
// Preserve the established internal handling of DXQ server data.
return;
}
@@ -2183,7 +2182,7 @@ public class MessageBusManagementThread extends Thread {
// e.printStackTrace();
// }
if (!On4KstProtocol.isConnectionProbeResponse(
if (!On4KstProtocol.isInternalDxqResponse(
messageTextRaw.getMessageText())) {
System.out.println(messageTextRaw.getMessageText() + " <- RXed"); // Stdout at
// Console#######################################################TODO:Wichtig
@@ -47,9 +47,7 @@ final class On4KstConnectionManager {
static final int CONNECT_TIMEOUT_MILLIS = 10_000; //TCP-Connect-Timeout
static final long LOGIN_FALLBACK_MILLIS = 2_000L; //Login-Fallback
static final long HANDSHAKE_TIMEOUT_MILLIS = 45_000L; //Handshake-Timeout
static final long APPLICATION_HEARTBEAT_AFTER_MILLIS = 90_000L; //Application-Heartbeat
/** 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 CLIENT_LIVENESS_PROBE_AFTER_MILLIS = 90_000L;
static final long INBOUND_STALE_AFTER_MILLIS = 210_000L; //Stale-Timeout - time without rxed data
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
@@ -181,10 +179,10 @@ final class On4KstConnectionManager {
session.lastProgressMillis.set(now);
String opcode = On4KstProtocol.opcode(line);
long probeResponseMillis = session.connectionProbe.acknowledge(now);
long probeResponseMillis = session.clientLivenessProbe.acknowledge(now);
if (probeResponseMillis >= 0L) {
LOGGER.log(Level.INFO,
"ON4KST connection probe confirmed: session {0}, "
"ON4KST client liveness probe confirmed: session {0}, "
+ "received opcode {1}, response time {2} ms",
new Object[] {
sessionId,
@@ -193,8 +191,8 @@ final class On4KstConnectionManager {
});
}
if ("CK".equals(opcode)) {
sendHeartbeat(session);
if (On4KstProtocol.isServerLivenessProbe(line)) {
sendServerLivenessProbeResponse(session);
}
if (!session.loginSent
@@ -265,8 +263,7 @@ final class On4KstConnectionManager {
token,
socket,
receiveQueue,
transmitQueue,
mainCategory);
transmitQueue);
ReadThread readThread = new ReadThread(
token, socket, receiveQueue, this::isActiveSession,
@@ -541,42 +538,35 @@ final class On4KstConnectionManager {
session.transmitQueue.offer(message);
}
private void sendHeartbeat(Session session) {
private void sendServerLivenessProbeResponse(Session session) {
if (session == null || !isActiveSession(session.id)) {
return;
}
long now = System.currentTimeMillis();
session.lastHeartbeatMillis.set(now);
LOGGER.log(Level.FINE,
"Sending application heartbeat for ON4KST session {0}",
"Responding to ON4KST server liveness probe: session {0}, "
+ "opcode CK",
session.id);
ChatMessage heartbeat = new ChatMessage();
heartbeat.setMessageDirectedToServer(true);
heartbeat.setMessageText("");
session.transmitQueue.offer(heartbeat);
sendControl(session, On4KstProtocol.serverLivenessProbeResponse());
}
private void sendConnectionProbe(
private void sendClientLivenessProbe(
Session session,
long now,
long inboundIdle
) {
if (session == null || !isActiveSession(session.id)
|| !session.connectionProbe.tryStart(now)) {
|| !session.clientLivenessProbe.tryStart(now)) {
return;
}
LOGGER.log(Level.INFO,
"Sending ON4KST connection probe: session {0}, main category "
+ "{1}, inbound idle {2} seconds",
"Sending ON4KST client liveness probe: session {0}, "
+ "opcode CK, inbound idle {1} seconds",
new Object[] {
session.id,
session.mainCategory,
inboundIdle / 1_000L
});
sendControl(
session,
On4KstProtocol.connectionProbe(session.mainCategory));
sendControl(session, On4KstProtocol.clientLivenessProbe());
}
private void onConnectionFailure(long sessionId, Throwable failure) {
@@ -682,8 +672,8 @@ final class On4KstConnectionManager {
long inboundIdle = now - lastInboundMillis;
IdleAction idleAction = determineIdleAction(
inboundIdle,
session.lastHeartbeatMillis.get() >= lastInboundMillis,
session.connectionProbe.isOutstanding());
session.online,
session.clientLivenessProbe.isOutstanding());
if (session.lastInboundMillis.get() != lastInboundMillis) {
return;
@@ -695,16 +685,15 @@ final class On4KstConnectionManager {
return;
}
long probeWaitMillis =
session.connectionProbe.responseWaitMillis(now);
session.clientLivenessProbe.responseWaitMillis(now);
if (probeWaitMillis >= 0L) {
LOGGER.log(Level.WARNING,
"ON4KST connection probe timed out: session "
+ "{0}, main category {1}, no response "
+ "for {2} ms, inbound idle {3} seconds; "
"ON4KST client liveness probe timed out: "
+ "session {0}, opcode CK, no response "
+ "for {1} ms, inbound idle {2} seconds; "
+ "reconnecting",
new Object[] {
session.id,
session.mainCategory,
probeWaitMillis,
inboundIdle / 1_000L
});
@@ -713,9 +702,8 @@ final class On4KstConnectionManager {
new SocketException("No ON4KST data received for "
+ inboundIdle / 1_000L + " seconds"));
}
case CONNECTION_PROBE ->
sendConnectionProbe(session, now, inboundIdle);
case HEARTBEAT -> sendHeartbeat(session);
case CLIENT_LIVENESS_PROBE ->
sendClientLivenessProbe(session, now, inboundIdle);
case NONE -> {
// The session is active or already has the required idle action.
}
@@ -731,19 +719,18 @@ final class On4KstConnectionManager {
*/
static IdleAction determineIdleAction(
long inboundIdleMillis,
boolean heartbeatSentForIdlePhase,
boolean online,
boolean probeOutstanding
) {
if (!online) {
return IdleAction.NONE;
}
if (inboundIdleMillis > INBOUND_STALE_AFTER_MILLIS) {
return IdleAction.TIMEOUT;
}
if (inboundIdleMillis >= CONNECTION_PROBE_AFTER_MILLIS
if (inboundIdleMillis > CLIENT_LIVENESS_PROBE_AFTER_MILLIS
&& !probeOutstanding) {
return IdleAction.CONNECTION_PROBE;
}
if (inboundIdleMillis > APPLICATION_HEARTBEAT_AFTER_MILLIS
&& !heartbeatSentForIdlePhase) {
return IdleAction.HEARTBEAT;
return IdleAction.CLIENT_LIVENESS_PROBE;
}
return IdleAction.NONE;
}
@@ -894,15 +881,13 @@ final class On4KstConnectionManager {
private final Socket socket;
private final LinkedBlockingQueue<ChatMessage> receiveQueue;
private final LinkedBlockingQueue<ChatMessage> transmitQueue;
private final int mainCategory;
private final long connectedMillis = System.currentTimeMillis();
private final AtomicLong lastInboundMillis =
new AtomicLong(connectedMillis);
private final AtomicLong lastProgressMillis =
new AtomicLong(connectedMillis);
private final AtomicLong lastHeartbeatMillis = new AtomicLong();
private final ConnectionProbeState connectionProbe =
new ConnectionProbeState();
private final ClientLivenessProbeState clientLivenessProbe =
new ClientLivenessProbeState();
private final Map<Integer, Map<String, ChatMember>> initialMembers =
new ConcurrentHashMap<>();
@@ -920,27 +905,24 @@ final class On4KstConnectionManager {
long id,
Socket socket,
LinkedBlockingQueue<ChatMessage> receiveQueue,
LinkedBlockingQueue<ChatMessage> transmitQueue,
int mainCategory
LinkedBlockingQueue<ChatMessage> transmitQueue
) {
this.id = id;
this.socket = socket;
this.receiveQueue = receiveQueue;
this.transmitQueue = transmitQueue;
this.mainCategory = mainCategory;
}
}
/** Maintenance action selected by the session monitor. */
enum IdleAction {
NONE,
HEARTBEAT,
CONNECTION_PROBE,
CLIENT_LIVENESS_PROBE,
TIMEOUT
}
/** Tracks one outstanding liveness probe for the complete TCP session. */
static final class ConnectionProbeState {
/** Tracks one client-initiated liveness probe for the complete TCP session. */
static final class ClientLivenessProbeState {
private final AtomicLong sentMillis = new AtomicLong();
boolean tryStart(long now) {
@@ -54,13 +54,32 @@ final class On4KstProtocol {
+ "|0|";
}
/** Builds the active liveness probe for the session's main chat. */
static String connectionProbe(int category) {
return "RDXQ|" + category(category) + "|";
/** Builds the session-wide liveness probe initiated by this client. */
static String clientLivenessProbe() {
return "CK|";
}
/** Returns whether a server frame is the expected liveness-probe response. */
static boolean isConnectionProbeResponse(String frame) {
/** Returns whether a server frame acknowledges a client-initiated probe. */
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));
}
@@ -86,11 +86,20 @@ public class ReadThread extends Thread {
throw new EOFException("ON4KST closed the TCP connection");
}
if (!sessionIsActive.test(sessionId)) {
break;
}
inboundActivity.accept(response);
if (!sessionIsActive.test(sessionId)) {
break;
}
if (On4KstProtocol.isClientLivenessProbeResponse(response)) {
// OK and OK| acknowledge the client-side CK| probe.
continue;
}
ChatMessage message = new ChatMessage();
message.setMessageText(response);
receiveQueue.put(message);
@@ -127,4 +136,4 @@ public class ReadThread extends Thread {
socket.close();
return true;
}
}
}
@@ -3,46 +3,63 @@ package kst4contest.controller;
import static org.junit.jupiter.api.Assertions.assertArrayEquals;
import static org.junit.jupiter.api.Assertions.assertEquals;
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 java.io.OutputStreamWriter;
import java.lang.reflect.Field;
import java.net.ServerSocket;
import java.net.Socket;
import java.nio.charset.StandardCharsets;
import java.time.Duration;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CountDownLatch;
import java.util.concurrent.LinkedBlockingQueue;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicLong;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.Timeout;
import kst4contest.model.ChatCategory;
import kst4contest.model.ChatMessage;
import kst4contest.model.ChatPreferences;
class On4KstConnectionProbeTest {
@Test
void buildsMainChatProbeAndAcceptsExpectedResponse() {
assertEquals("RDXQ|2|", On4KstProtocol.connectionProbe(2));
assertTrue(On4KstProtocol.isConnectionProbeResponse("DXQ|2|data|"));
assertFalse(On4KstProtocol.isConnectionProbeResponse(
"CH|2|123|DL1ABC|Name|0|text|0|"));
void separatesClientProbeServerProbeAndInternalResponses() {
assertEquals("CK|", On4KstProtocol.clientLivenessProbe());
assertTrue(On4KstProtocol.isClientLivenessProbeResponse("OK"));
assertTrue(On4KstProtocol.isClientLivenessProbeResponse("OK|"));
assertFalse(On4KstProtocol.isClientLivenessProbeResponse(
"OK|unexpected|"));
assertTrue(On4KstProtocol.isServerLivenessProbe("CK|"));
assertEquals("", On4KstProtocol.serverLivenessProbeResponse());
assertTrue(On4KstProtocol.isInternalDxqResponse("DXQ|2|data|"));
}
@Test
void selectsHeartbeatProbeAndTimeoutAtIdleBoundaries() {
void selectsOneClientProbeAndTimeoutAtIdleBoundaries() {
assertEquals(
On4KstConnectionManager.IdleAction.NONE,
idleAction(90_000L, false, false));
assertEquals(
On4KstConnectionManager.IdleAction.HEARTBEAT,
idleAction(90_001L, false, false));
idleAction(90_000L, true, false));
assertEquals(
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(
On4KstConnectionManager.IdleAction.CONNECTION_PROBE,
idleAction(180_000L, true, false));
On4KstConnectionManager.IdleAction.CLIENT_LIVENESS_PROBE,
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(
On4KstConnectionManager.IdleAction.NONE,
idleAction(210_000L, true, true));
@@ -52,9 +69,9 @@ class On4KstConnectionProbeTest {
}
@Test
void oneSessionProbeIsAcknowledgedByAnyInboundTraffic() {
On4KstConnectionManager.ConnectionProbeState probe =
new On4KstConnectionManager.ConnectionProbeState();
void sessionProbeCoversTwoCategoriesAndRepeatedIdlePhases() {
On4KstConnectionManager.ClientLivenessProbeState probe =
new On4KstConnectionManager.ClientLivenessProbeState();
assertTrue(probe.tryStart(1_000L));
assertFalse(probe.tryStart(1_001L),
@@ -71,8 +88,8 @@ class On4KstConnectionProbeTest {
@Test
@Timeout(5)
void writerUsesExactCrLfForHeartbeatAndConnectionProbe() throws Exception {
byte[] expected = "\r\nRDXQ|2|\r\n".getBytes(StandardCharsets.UTF_8);
void writerUsesExactBytesForClientAndServerLivenessFrames() throws Exception {
byte[] expected = "CK|\r\n\r\n".getBytes(StandardCharsets.UTF_8);
try (ServerSocket server = new ServerSocket(0)) {
CompletableFuture<byte[]> received = CompletableFuture.supplyAsync(() -> {
@@ -98,8 +115,9 @@ class On4KstConnectionProbeTest {
ignored -> { });
writer.start();
queue.add(serverFrame(""));
queue.add(serverFrame(On4KstProtocol.connectionProbe(2)));
queue.add(serverFrame(On4KstProtocol.clientLivenessProbe()));
queue.add(serverFrame(
On4KstProtocol.serverLivenessProbeResponse()));
assertArrayEquals(
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(
long inboundIdleMillis,
boolean heartbeatSent,
boolean online,
boolean probeOutstanding
) {
return On4KstConnectionManager.determineIdleAction(
inboundIdleMillis,
heartbeatSent,
online,
probeOutstanding);
}
@@ -129,4 +286,55 @@ class On4KstConnectionProbeTest {
message.setMessageText(text);
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();
}
}
}