Skip to content

Add network diagnostics logging and migrate to tinylog#10004

Merged
tool4ever merged 2 commits intoCard-Forge:masterfrom
MostCromulent:network-diagnostics-logging
Mar 7, 2026
Merged

Add network diagnostics logging and migrate to tinylog#10004
tool4ever merged 2 commits intoCard-Forge:masterfrom
MostCromulent:network-diagnostics-logging

Conversation

@MostCromulent
Copy link
Contributor

@MostCromulent MostCromulent commented Mar 7, 2026

Summary

Existing logging uses System.out.println (no timestamps) and provided no performance metrics, making it impossible to identify bottlenecks from log files alone.

Migrates all network System.out/System.err logging to tinylog (Logger) and adds targeted performance diagnostics with thresholds to avoid log noise during normal play.

Changes

1. tinylog Migration (all network classes)

Every System.out.println and System.err.println call in the network package is replaced with the appropriate Logger.info, Logger.warn, or Logger.error call. This ensures every log line gets a timestamp, log level, and thread name — critical for correlating events between server and client logs.

Files: GameProtocolHandler, FGameClient, FServerManager, GameClientHandler, ProtocolMethod, TrackableTypes

2. Protocol Processing Duration (GameProtocolHandler)

Measures wall-clock time for method.invoke() execution and EDT queue delay (time between message arrival on the IO thread and actual processing on the EDT). Logged only when either exceeds 50 ms — a threshold chosen as the point where per-message delay becomes perceptible. Normal protocol calls complete in single-digit milliseconds, so this fires only on genuine bottlenecks.

3. IO-Thread beforeCall() Timing (GameProtocolHandler)

Measures time spent in beforeCall(), which runs on Netty's single IO thread and includes updateTrackers() and replicateProps(). Logged only above 50 ms. This is the most likely cause of the reported multi-second delays — beforeCall() blocks ALL subsequent network messages, so if it's slow, every message in the pipeline backs up. Normal execution is sub-millisecond.

4. send() Duration (RemoteClient)

Measures how long writeAndFlush().sync() blocks the calling thread. Logged only above 50 ms. Detects TCP back-pressure or slow client acknowledgment causing the server game thread to stall. Under normal network conditions this completes near-instantly.

5. Serialization Size Logging (CompatibleObjectEncoder / CompatibleObjectDecoder)

Logs compressed frame size and decode duration for messages exceeding 20 KB compressed. Normal setGameView packets are ~8–15 KB compressed in 2-player games, so the 20 KB threshold fires selectively — primarily on 4-player games (~15–25 KB compressed) and anomalously large 2-player states. Decode duration is also logged above 50 ms to catch deserialization bottlenecks.

6. Event Type Identification (NetGuiGame)

Logs the class names of game events in each batch sent to the client. Correlates server-side event batches with client-side processing delays to identify which game actions trigger the heaviest network traffic.


🤖 Generated with Claude Code

- Migrate all System.out/err in network package to Logger (tinylog)
  so every log line gets timestamps
- Add processing duration and EDT queue delay timing (>50ms threshold)
- Add beforeCall() IO-thread timing to detect tracker bottlenecks
- Add server-side send() duration to detect write stalls
- Log game event types in batches for correlation
- Log serialized message size and decode duration (>10KB or >50ms)

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
@tool4ever tool4ever merged commit b166223 into Card-Forge:master Mar 7, 2026
2 checks passed
@MostCromulent MostCromulent deleted the network-diagnostics-logging branch March 7, 2026 10:20
MostCromulent added a commit to MostCromulent/forge that referenced this pull request Mar 8, 2026
Resolve conflicts from network diagnostics logging PR (Card-Forge#10004) and
cleanup PR (Card-Forge#10002). All network logging routes through
NetworkDebugLogger (tinylog NETWORK tag) for separate log files.
Port new diagnostic instrumentation (decode timing, beforeCall timing,
EDT queue delay, protocol processing time, send() blocking, large
message detection) via NetworkDebugLogger. Take master's
updateLobbyState() call in RegisterClientHandler.channelActive().

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants