Skip to content

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

Open
Greg Lamberson (glamberson) wants to merge 1 commit into
Devolutions:masterfrom
lamco-admin:feat/server-egfx-dispatch-diagnostics
Open

feat(server): add diagnostic logging for EGFX flow control and dispatch timing#1834
Greg Lamberson (glamberson) wants to merge 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 maintainer-required Maintainer review or intervention is required 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
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

maintainer-required Maintainer review or intervention is required 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.

1 participant