Skip to content

feat(server): add diagnostic logging for EGFX flow control and dispatch timing - #1834

Merged
Marc-André Moreau (mamoreau-devolutions) merged 1 commit into
Devolutions:masterfrom
lamco-admin:feat/server-egfx-dispatch-diagnostics
Aug 30, 2026
Merged

Marc-André Moreau (mamoreau-devolutions) merged 1 commit into
Devolutions:masterfrom
lamco-admin:feat/server-egfx-dispatch-diagnostics

Conversation

@glamberson

Copy link
Copy Markdown
Contributor

I ran into a case where I needed to debug slow frame acknowledgement and dispatch stalls in ironrdp-server and ironrdp-egfx, and found the relevant signals were either missing or buried at TRACE level where nobody enables them in normal operation. This PR adds targeted diagnostic logging without changing any behavior.

  • FrameTracker now edge-triggers a debug log when backpressure or ack_suspended change state, instead of logging every call (which would flood at 30+/sec) or nothing at all.
  • FrameAcknowledge is now logged at DEBUG with latency, queue_depth, and in-flight count. An ack for an unknown frame_id (protocol violation or stale ack per MS-RDPEGFX 2.2.4.3) is now a warning instead of silent.
  • drain_output (ZGFX compression) now tracks per-batch compress time and ratio, logging at INFO when a batch exceeds a 10ms budget and DEBUG otherwise, since it runs under both the state lock and the writer lock and can block inbound PDU processing.
  • Incoming EGFX DVC PDUs are logged at DEBUG with their kind, so the client-to-server side of the channel is visible without enabling TRACE.
  • dispatch_pdu and dispatch_events now separately time lock-acquisition wait and handler dispatch, warning when either exceeds 50ms so the two causes (lock contention vs. handler/runtime stall) can be told apart instead of both surfacing as one generic slow-dispatch symptom.

No public API changes, no behavioral changes, logging only.

Note on CI: the workspace-wide test compile is currently broken on master independent of this PR, ironrdp-daemon's consume_output() call site passes a raw Receiver where OutputEventReceiver is expected. I confirmed this reproduces on a clean, unmodified checkout of master. This PR only touches ironrdp-server and ironrdp-egfx.

@github-actions github-actions Bot added needs-review A human reviewer is the current next actor risk/unknown Risk could not be determined automatically; needs maintainer-level scrutiny scope/core Touches the core architectural tier size/M Size: up to 449 counted lines and 10 files; exceeds S in either measure labels Aug 29, 2026
…ispatch timing

The EGFX flow-control loop (backpressure, ack_suspended, FrameAcknowledge)
and the server's per-PDU dispatch loop were both effectively invisible at
default log levels. FrameAcknowledge, the single most important signal in
the flow-control loop, was only logged at TRACE. Backpressure/ack_suspended
transitions were not logged at all, and dispatch_pdu had no way to
distinguish lock contention from a slow handler or runtime stall.

- FrameTracker now edge-triggers a debug log when backpressure or
  ack_suspended change state, instead of logging every call (which would
  flood at 30+/sec) or nothing at all.
- FrameAcknowledge is now logged at DEBUG with latency, queue_depth, and
  in-flight count. An ack for an unknown frame_id (protocol violation or
  stale ack per MS-RDPEGFX 2.2.4.3) is now a warning instead of silent.
- drain_output (ZGFX compression) now tracks per-batch compress time and
  ratio, logging at INFO when a batch exceeds a 10ms budget and DEBUG
  otherwise, since it runs under both the state lock and the writer lock
  and can block inbound PDU processing.
- Incoming EGFX DVC PDUs are logged at DEBUG with their kind, so the
  client-to-server side of the channel is visible without enabling TRACE.
- dispatch_pdu and dispatch_events now separately time lock-acquisition
  wait and handler dispatch, warning when either exceeds 50ms so the two
  causes (lock contention vs. handler/runtime stall) can be told apart
  instead of both surfacing as one generic slow-dispatch symptom.
@glamberson
Greg Lamberson (glamberson) force-pushed the feat/server-egfx-dispatch-diagnostics branch from b7ed25a to b0c44ac Compare August 29, 2026 13:50
@glamberson Greg Lamberson (glamberson) changed the title feat(server,egfx): add diagnostic logging for EGFX flow control and dispatch timing feat(server): add diagnostic logging for EGFX flow control and dispatch timing Aug 29, 2026
@mamoreau-devolutions
Marc-André Moreau (mamoreau-devolutions) merged commit 8d1e91e into Devolutions:master Aug 30, 2026
58 of 60 checks passed
Anton Mostovoy (antonmos) added a commit to antonmos/IronRDP that referenced this pull request Aug 30, 2026
…arge pointer capset)

Three upstream commits since the last sync, all in client_accepted's
capability loop or client_loop's body -- code this branch has never
touched (the preemption/negotiation work stays entirely within
PendingConnection/negotiate_and_authenticate and the accept-loop race,
upstream of accept_finalize where client_accepted/client_loop live):

Devolutions#1787! (Large Pointer Capability Set) -- additive to the capabilities
match in client_accepted and UpdateEncoder::new's constructor, neither
touched here.
Devolutions#1834 (EGFX flow-control + dispatch timing diagnostics) -- logging only
inside client_loop's existing futures, no signature changes.
Devolutions#1842 (periodic Heartbeat PDUs) -- adds a field + a config setter to
RdpServer and a 5th joined future inside client_loop; client_loop's own
signature gained a parameter, but its only two call sites (both inside
client_accepted) are upstream's own code, already updated by the merge.

One trivial conflict: both branches touched the same two import lines
at the top of the file (this branch added IpAddr for the anti-storm
cooldown's EvictedPeer.ip; upstream added AtomicU64 for the heartbeat
write-counter) -- kept both.

Note from Devolutions#1834's own commit message, checked rather than trusted: it
warns the workspace-wide test build was already broken on master
independent of that PR (an ironrdp-daemon call-site mismatch). Did not
reproduce here -- full cargo build --workspace succeeded clean, so
either it was already fixed by a later commit or doesn't affect a
non-test build; not chased further since it doesn't block this merge.

14/14 tests pass in both default and --features egfx (test count
unchanged -- none of the three commits touch a test module), clippy
--all-targets clean in both configs AND under CI's exact stricter
command (--features helper,__bench --locked -- -D warnings), fmt clean,
full cargo build --workspace green.
@glamberson
Greg Lamberson (glamberson) deleted the feat/server-egfx-dispatch-diagnostics branch August 30, 2026 15:12

This branch was previously deployed

1 inactive deployment
llm-providers — b0c44ac4 Deployed Aug 29, 2026 by glamberson via Classify pull request #4393
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

needs-review A human reviewer is the current next actor risk/unknown Risk could not be determined automatically; needs maintainer-level scrutiny scope/core Touches the core architectural tier size/M Size: up to 449 counted lines and 10 files; exceeds S in either measure

Development

Successfully merging this pull request may close these issues.

2 participants