Skip to content

UCP/WIREUP: Improve p2p lane matching diagnostics - #11912

Merged
tvegas1 merged 3 commits into
openucx:masterfrom
tvegas1:wireup_logs
Sep 11, 2026
Merged

UCP/WIREUP: Improve p2p lane matching diagnostics#11912
tvegas1 merged 3 commits into
openucx:masterfrom
tvegas1:wireup_logs

Conversation

@tvegas1

@tvegas1 tvegas1 commented Sep 7, 2026

Copy link
Copy Markdown
Contributor

What?

Improve wireup p2p lane matching diagnostics, and report an ep address overflow as a fatal error instead of a debug-only assertion.

Related: https://nvbugspro.nvidia.com/bug/6665318

Why?

When an endpoint selects more lanes toward a remote device than the peer packed ep addresses for, ucp_wireup_match_p2p_lanes() reads past ep_addrs[]: debug builds assert, release builds pick up a zeroed entry and die later with a message naming neither the local device nor the remote address entry. Diagnosing it required the peer's pack traces to learn which devices addr[N] and each lane referred to.

How?

Ep address overflow, now fatal in release builds too:

- Assertion `ep_addr_index < address->num_ep_addrs' failed: lane=7/14 tl_name_csum=0xd47a address_index=3 ep_addr_index=2 num_ep_addrs=2
+ Fatal: ep 0xfffd7c000140: lane[7] rc_mlx5/mlx5_0:1.1 -> addr[3] rc_mlx5: no ep address 2, only 2 provided

Duplicate remote lane:

- Fatal: ep 0xfffd7c000140: remote lane 0 is used more than once
+ Fatal: ep 0xfffd7c000140: lane[7] rc_mlx5/mlx5_0:1.1 -> addr[3]: remote lane 0 is used more than once

Missing remote ep address in ucp_wireup_connect_local():

- ep 0xfffd7c000140: no remote ep address for lane[2]->remote_lane[5]
+ ep 0xfffd7c000140: lane[2] rc_mlx5/mlx5_1:1.0: no remote ep address for remote lane 5

Lane construction trace, the only lane-to-device record when an unchanged config skips ucp_wireup_print_config():

- ep 0xfffd7c000140: construct lane 7 to addr_index 3
+ ep 0xfffd7c000140: construct lane 7 rc_mlx5/mlx5_0:1.1 to addr_index 3
- ep 0xfffd7c000140: construct lane 0 to addr_index 4294967295
+ ep 0xfffd7c000140: construct lane 0 cm

Address unpack trace, so the receiver's log is self-describing:

- unpack addr[3] : sysdev 6 paths 2 eps 2 tl_flags 0x39a bw 45747.33/nMBs ...
+ unpack addr[3] : rc_mlx5 md[7] sysdev 6 paths 2 eps 2 tl_flags 0x39a bw 45747.33/nMBs ...

Report the local interface, path index and remote address entry when p2p
lane matching runs out of remote ep addresses or hits a duplicate remote
lane, and turn the ep address bounds assertion into a fatal error so
release builds report it instead of reading past the ep address array.

Also name the local interface in the lane construction trace and the
remote transport and md index in the address unpack trace, so a log alone
maps lanes and address entries to devices.
@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Starting review — findings will be posted here when done.

@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Review complete — no issues found.

Comment thread src/ucp/wireup/wireup.c Outdated
@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Starting review — findings will be posted here when done.

@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Review complete — no issues found.

Comment thread src/ucp/core/ucp_ep.h Outdated
Define UCP_EP_LANE_FMT and UCP_EP_LANE_ARG next to the other ucp_ep.h
macros instead of in the middle of the function prototype list.
@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Starting review — findings will be posted here when done.

@svc-nvidia-pr-review

Copy link
Copy Markdown

🤖 Review complete — no issues found.

@svc-ucx

svc-ucx commented Sep 8, 2026

Copy link
Copy Markdown

🤖 CI Triage AgentUCX PR (Tests roce on worker 1) · commit 5c7535d7

TL;DR: The gtest binary was aborted by the 900-second watchdog while rc_verbs/test_uct_peer_failure_keepalive.killed_post_am/1 <rc_verbs/mlx5_1:1> hung forever inside uct_test::flush() polling the RC CQ after the receiver was destroyed; this is a UCT-level peer-failure/keepalive hang unrelated to the PR's UCP wireup-log changes, made fatal by uct_test::flush()'s unbounded default deadline.

Full analysis

Summary: roce on worker 1 job failed with make: *** [Makefile:4713: test] Aborted (core dumped) — watchdog timeout (Connection timed out - abort testing, test_helpers.cc:57) fired during test_uct_peer_failure_keepalive.killed_post_am/1 on rc_verbs/mlx5_1:1.

Root cause: This is a hang, not a slow job. The log shows continuous test activity (sub-second per test) until [ RUN ] rc_verbs/test_uct_peer_failure_keepalive.killed_post_am/1 at 14:39:57.98, then a single gap of exactly 900 s with zero output, ending at 14:54:57.46 when the gtest watchdog (watchdog_timeout = 900. in test/gtest/common/test_helpers.cc:31) called ADD_FAILURE() + pthread_kill (SIGTERM → signal 6 abort). The captured backtrace pinpoints the stuck frame:

test_uct_peer_failure_keepalive::test_ep_check()uct_test::flush() (test/gtest/uct/uct_test.cc:772) → uct_worker_progressuct_rc_verbs_iface_progress (rc_verbs_iface.c:174) → uct_ib_poll_cq.

That is the flush() call performed after kill_receiver() + uct_ep_check() + the in-flight uct_ep_am_short() (master equivalent: test/gtest/uct/test_peer_failure.cc:698). On this RoCE device the failed endpoint's outstanding AM/keepalive never completes and never reports an error, so uct_iface_flush() keeps returning UCS_INPROGRESS. Because uct_test::flush() defaults to deadline = ULONG_MAX (test/gtest/uct/uct_test.h:406), the loop spins indefinitely instead of failing the single test — so the whole gtest binary is killed and the job dies.

Nothing in the failing path involves UCP wireup: the test is pure UCT (rc_verbs iface/ep, error handler, keepalive), so PR #11912 ("wireup_logs", commit 5c7535d) is almost certainly not the trigger — this looks like a flaky/environmental RoCE peer-failure hang on swx-rain03/mlx5_1:1.

Implicated commit: unknown — not attributable to 5c7535d (UCP wireup logging). Most plausible related changes to the RC keepalive/error-detection path are 33e7d1d "UCT/EP: Enhance uct_ep_check (#11495)" (Evgeny Leksikov) and the in-progress error-handler work in #11829.

File: test/gtest/uct/test_peer_failure.cc:698 (the flush() after kill_receiver()), hang made unbounded by test/gtest/uct/uct_test.h:406; watchdog at test/gtest/common/test_helpers.cc:57

Suggested fix:

  1. Re-run the job to confirm flakiness and un-block the PR — the failure is not caused by the wireup-log changes.
  2. Make the hang non-fatal and diagnosable: pass an explicit deadline in test_ep_check() (e.g. flush(ucs::get_deadline())) instead of relying on the ULONG_MAX default, so one stuck endpoint fails that test rather than aborting the entire gtest run. Consider changing uct_test::flush()'s default deadline from ULONG_MAX to a bounded value.
  3. Investigate the real UCT bug: on RoCE rc_verbs, after kill_receiver() destroys the peer iface, the in-flight AM-short/keepalive on the failed EP never produces a CQ error, so uct_iface_flush() never leaves UCS_INPROGRESS. Verify that the test's set_config("RC_TIMEOUT?=100us") / RC_RETRY_COUNT?=4 are actually taking effect in the RoCE job (the ?= form is a no-op if UCX_RC_TIMEOUT/UCX_RC_RETRY_COUNT are already set in that worker's environment) — if the retransmit timeout stays at the default, RETRY_EXC may never be reached within the watchdog window.

Related: PR #11912 (this build), PR #11495 (uct_ep_check enhancement), PR #11829 (UCT/IB/MLX5 in-progress error handler)

@tvegas1
tvegas1 merged commit 858ffea into openucx:master Sep 11, 2026
162 checks passed
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.

4 participants