Skip to content

fix(rpc): additional logs#1175

Open
wyzula-jan wants to merge 6 commits into
mainfrom
fix/rpc-timeout-logging
Open

fix(rpc): additional logs#1175
wyzula-jan wants to merge 6 commits into
mainfrom
fix/rpc-timeout-logging

Conversation

@wyzula-jan
Copy link
Copy Markdown
Contributor

@wyzula-jan wyzula-jan commented May 22, 2026

Description

Adds RPC timeout diagnostics for BEC Widgets so client, dispatcher, and RPC server logs can be correlated by request_id.

Also:

  • Increases default GUI RPC timeout from 5s to 60s
  • Disables noisy bec_lib.scan_items logs in BEC Widgets
  • Keeps flOMNI GUI calls on the shared client default timeout instead of local custom timeouts

What Is Logged

Client side:

  • RPC request sent
  • RPC response received
  • RPC response timeout

Dispatcher side:

  • RPC request received before Qt callback emit
  • Warning if request already passed the client deadline at dispatcher receipt

RPC server side:

  • RPC request entered on_rpc_update
  • Warning if it entered after the client deadline
  • RPC execution finished
  • Warning if execution finished after the client deadline
  • RPC response published
  • RPC result serialization retry delayed by QTimer.singleShot

Important Log Fields

  • request_id: correlate logs for one RPC call
  • method: RPC method/action
  • receiver / gui_id: target and handling GUI server ids
  • target_gui_id: target widget/object id
  • object_name: client-side proxy name
  • timeout: client RPC timeout
  • dispatch_latency_s: client send to dispatcher receipt
  • stale_on_dispatch: dispatcher received after client deadline
  • receive_latency_s: client send to on_rpc_update
  • stale_on_receive: RPC handler started after client deadline
  • execution_duration_s: RPC method execution time
  • response_after_client_deadline: execution finished after client deadline
  • accepted: response success state
  • args / kwargs: bounded RPC method arguments

Additional Comments

This distinguishes Redis/dispatcher delay, Qt/RPC handler delay, slow/stuck widget execution, and responses published too late for the client.

Copilot AI review requested due to automatic review settings May 22, 2026 12:49
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR adds richer, structured logging around GUI RPC request sending, server-side receipt/execution, and response publishing to improve observability and debugging of RPC timing and failures.

Changes:

  • Add client-side RPC logs and attach timing/identifying metadata (sent_at, deadline, timeout, etc.) to outgoing RPC messages.
  • Add server-side logs for RPC receipt latency, execution duration, and “stale/late” request/response detection.
  • Add unit tests validating the new logging behavior.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.

File Description
bec_widgets/utils/rpc_server.py Adds receipt/execution/response logs, timing helpers, and “stale/late” warnings on the server side.
bec_widgets/cli/rpc/rpc_base.py Adds request/response logging and enriches outgoing RPC metadata with timing/identity fields.
tests/unit_tests/test_rpc_server.py Adds tests asserting server logs for publish status and late-deadline handling.
tests/unit_tests/test_rpc_base.py Adds a test asserting client-side timeout logging + metadata population on timeout.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread bec_widgets/utils/rpc_server.py
@wyzula-jan wyzula-jan force-pushed the fix/rpc-timeout-logging branch from eea3aaf to 00fa1a9 Compare May 22, 2026 13:00
@wyzula-jan wyzula-jan force-pushed the fix/rpc-timeout-logging branch from 00fa1a9 to bfea216 Compare May 22, 2026 13:00
@github-actions
Copy link
Copy Markdown
Contributor

github-actions Bot commented May 22, 2026

Benchmark comparison

Threshold: 20% (lower is better).
Result: 0 regression(s), 0 improvement(s) beyond threshold.

No benchmark regression exceeded the configured threshold.

No benchmark improvement exceeded the configured threshold.

All benchmark results
Benchmark Baseline Current Change Status
BEC IPython client with companion app 5.91908 s 5.98198 s +1.06% ok
BEC IPython client without companion app 2.21378 s 2.01084 s -9.17% ok
Import bec_widgets 0.0143291 s 0.013889 s -3.07% ok
tests/unit_tests/benchmarks/test_dock_area_benchmark.py::test_add_waveform_to_dock_area 0.151597 s 0.147184 s -2.91% ok

@codecov
Copy link
Copy Markdown

codecov Bot commented May 22, 2026

Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Copilot reviewed 10 out of 10 changed files in this pull request and generated 1 comment.

Comment thread bec_widgets/cli/rpc/rpc_base.py Outdated
@wyzula-jan wyzula-jan force-pushed the fix/rpc-timeout-logging branch from 2440df4 to 5b54ab1 Compare May 22, 2026 15:42
@wyzula-jan wyzula-jan requested a review from a team May 22, 2026 16:05
@wyzula-jan wyzula-jan enabled auto-merge (rebase) May 22, 2026 16:05
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