[Bug] Cross-card microsecond timestamps show stable per-device clock offsets #2397

Activity

1. Mewtwo-Jieyu commented on Sep 20, 2026

   

   Mewtwo-Jieyu

   on Sep 20, 2026

   Author

   More actions

   

   pypto-cross-card-timing-repro-20260920.tar.gz

   Attachments:

   • fig-clock-offset-en.png — visual summary
   • pypto-cross-card-timing-repro-20260920.tar.gz — sanitized reproduction package

   SHA-256:
   e24340122f13d7c0545b96f29b53bc1fb788eef059530436342ecd13bd39026f
2. ChaoZheng109 commented on Sep 22, 2026

   

   ChaoZheng109

   on Sep 22, 2026

   Collaborator

   More actions

   First: your analysis is correct. Cross-device timestamp subtraction is not valid on this runtime, the stable per-device offset is real, and the NUMA-shaped receive penalty it produces is an artifact. Thank you for the controls — the falsification work is what makes this actionable rather than a guess.

   Q1 — Are cross-device timestamps guaranteed to share a common epoch?

   No, and this is by design, not a regression. aclrtEventGetTimestamp returns device-uptime microseconds — each device's origin is its own power-on instant. The swimlane records use get_sys_cnt, which shares that epoch after frequency normalization (verified on a2a3 silicon):

   // src/a2a3/platform/include/common/platform_config.h:225-229
   // aclrtEventGetTimestamp capability, verified on a2a3 silicon: the raw value
   // is device-uptime microseconds and covers the same epoch as profiling syscnt
   // after frequency normalization.
   constexpr const char *PLATFORM_ACL_EVENT_TIMESTAMP_UNIT = "device_uptime_us";

   There is no cross-device clock synchronization step anywhere in runtime initialization. Cross-device subtraction of swimlane timestamps is unsupported.

   Q2 — Can the runtime expose a clock-domain ID and an offset/correlation record?

   • Offset/correlation record: it already exists. clock_anchors is serialized into every capture taken with CallConfig.capture_clock_anchors (set automatically for an L3 chip-swimlane capture). See the "existing mechanism" section below.
   • Clock-domain ID: host side only. metadata.host_clock_domain_id (derived from the Linux boot ID) exists and is used to refuse cross-host merges. There is no device-side equivalent. The host-side precedent could be copied if this is pursued, but it would be a new feature request.
   • Documentation: we will state the constraint explicitly. The swimlane docs should say that device timestamps are per-device uptime and that cross-device subtraction is unsupported. The absence of that sentence is the root cause of the misreading, and that part is our defect.

   Q3 — Is there an official device-clock synchronization or calibration API?

   No. The only timestamp-related surfaces in the ACL headers are:

   aclrtEventGetTimestamp(event, &ts)               // one device, absolute uptime, 1 us resolution
   aclrtEventElapsedTime(&ms, startEvent, endEvent) // interval between two events on the same device

   Worth stating explicitly because the naming misleads: every aclrtSynchronize* entry point is execution synchronization, not clock synchronization. There is no cross-device clock sync or calibration API.

   Q4 — Is the offset expected, and is the NUMA correlation expected?

   • The stable offset: expected. Independent per-device uptime origins necessarily produce one. -3 to +6 us is consistent with that semantics.
   • The NUMA parity correlation: we cannot confirm this. Power-on and reset ordering is driver and firmware behavior; this runtime neither controls nor observes it. The plausible mechanism is that device index, NUMA node and initialization batching are already correlated, so offsets group by NUMA as a side effect — but that is a conjecture, not a finding. This part needs the driver team.

   What is and is not measurable — the algebra

   This bounds what any calibration can deliver. With a four-timestamp ping-pong (t11 send on A, t21 receive on B, t22 send on B, t12 receive on A), writing o = o_B - o_A:

   t12 - t11 = d1 + tau + d2      # all on A's clock, offset-free
   t22 - t21 = tau                # all on B's clock, offset-free
   t21 - t11 = d1 + o             # the only cross-clock term
   

   • RTT = d1 + d2 = (t12 - t11) - (t22 - t21) is exact and assumption-free — two same-clock differences, o never enters. Your same-clock RTT probe already computes this correctly.
   • d1 and o are not separately identifiable. Two equations, three unknowns. Adding more timestamps does not help: o can only enter through a cross-clock term, and every cross-clock term brings in a new d.

   So RTT/2 is the supported limit today, and its residual is exactly (d1 - d2)/2. Your D'(s -> R) is the t21 - t11 term, = d1 + o, which is why the matrix shows a sender row plus a receiver column.

   One blind spot worth flagging in your own controls

   Your overlapping-group closure checks are good practice, but they cannot detect the residual above. Modelling one-way latency as L(s -> R) = T_s + P + R_R:

   delta(A,B) = L(A->B) - L(B->A) = (T_A - R_A) - (T_B - R_B)
   

   This is a per-device difference — algebraically the same form as a clock offset. Two consequences:

   1. It is indistinguishable from o in the joint fit, so your RMS 0.24 us does not bound it.
   2. Its ring sum is identically zero, so closure checks pass perfectly regardless of its magnitude.

   Both of your methods (joint fit and RTT/2) traverse the inter-card link and assume link symmetry, so they share this blind spot and their mutual agreement does not constrain it. That is not a criticism of the work — it is a limit of any link-based method.

   What exists today for cross-card alignment (coarse scale)

   simpler_setup.tools.swimlane_converter already merges multiple ranks onto one host CLOCK_MONOTONIC timeline:

   python -m simpler_setup.tools.swimlane_converter \
       build_output/<case>/dfx_outputs --dispatch-id RUN_ID:TASK_SLOT

   It works by span containment, not calibration: each rank's device block is placed at the earliest host ns its runner_run window allows, and the spare width is published as slack_ns per rank plus cross_rank_uncertainty_ns (the sum of the two widest slacks). The guarantee is one-sided — containment cannot be wrong, only loose.

   This will not help you at microsecond scale. For a capture-enabled run the collector teardown falls inside runner_run, so slack is absorbed and can reach hundreds of milliseconds. We mention it because its failure mode is the opposite of naive subtraction: a correct-but-useless interval rather than a confidently wrong number.

   Existing mechanism: host-anchored clock correlation (available now)

   We have already implemented a host-anchored sampler, which is the construction that can close the missing equation — it never traverses the inter-card link and therefore introduces no new d. It lives in src/common/platform/onboard/host/clock_correlation.cpp and is gated by CallConfig.capture_clock_anchors:

   h0 = host monotonic clock (std::chrono::steady_clock, same-host cross-process comparable)
   aclrtRecordEvent(event, stream)
   aclrtSynchronizeEvent(event)
   aclrtEventGetTimestamp(event, &Td)
   h1 = host monotonic clock
   
   o ~= Td - (h0 + h1) / 2
   

   Once each device is referenced to the host, the devices are aligned to each other transitively: in o_A - o_B the common host reference cancels exactly, and so does every host-side overhead common to all devices. Simultaneous sampling across devices is not required.

   o carries error too, and this is the important part. The error model:

   • The event necessarily executed within [h0, h1], so o_true lies in [Td - h1, Td - h0]. This is a hard bound, not an estimate — path asymmetry is contained within it rather than being an extra unbounded term.
   • Per device, |error| <= (h1 - h0) / 2; for a pairwise difference the two half-widths add.
   • The floor is set by the 1 us quantization of aclrtEventGetTimestamp: roughly 1 us per device, 2 us pairwise. That floor is independent of the sample count.

   You do not have to rely on our numbers — this error is already serialized per sample in your own captures. chip_swimlane_collector.cpp writes rtt_ns and uncertainty_ns = (rtt_ns+1)/2 for every anchor sample, plus a run-level host_timeline_origin_ns. Enable capture_clock_anchors, run once, and read clock_anchors.samples[].uncertainty_ns to get the actual error magnitude in your environment.

   Three known limitations of the current implementation, which you may want to address first if you pursue this:

   1. It uses a blocking aclrtSynchronizeEvent, whose wakeup latency lands inside [h0, h1]. Derived from the documented anchor cost (475-696 us per launch, 6 samples, cold sample 83-89%), the warm bracket is approximately 15 us — large relative to a 3-6 us signal. This is a derivation from published cost figures, not a direct measurement. Spinning on aclrtQueryEventStatus instead would replace the wakeup latency with a single query round trip.
   2. aclrtEventGetTimestamp is currently called before h1. Since the timestamp is frozen when the event executes on device and a later read returns the same instant, moving the call after h1 removes the readback cost from the bracket at no cost.
   3. kClockAnchorSamplesPerPosition = 3 is too few for interval intersection. Every sample's interval provably contains the true offset, so intersecting them remains a hard bound while being strictly tighter — that is the correct way to tighten it, rather than averaging.

   Also note that the offline tools no longer consume clock_anchors (placement moved to span containment, see docs/dfx/chip-swimlane-profiling.md:613). The data and schema are still produced, but you would need to parse them yourself.

   Whether that error is adequate is your call

   We cannot judge this for you — it depends on the magnitude you need to resolve:

   • If a +/-2 us hard bound is sufficient, the approach is viable. It is enough to independently confirm your fitted offsets (3-6 us scale) and to rule out link asymmetry above that magnitude — the term you currently cannot check at all.
   • If you need to resolve 0.3 us (for instance to validate your corrected 12.8 vs 12.5 us result), this method cannot do it as a hard bound. Getting to that scale requires a statistical estimate instead (filter, then average, relying on the sub-microsecond phase being uniformly distributed), which reintroduces assumptions and gives up the one advantage the hard bound has.

   The value of this mechanism is independence, not precision: your estimate is precise but may carry an unmeasured common bias, whereas a host-anchored bound is coarse but provably contains the truth. The two are complementary.

   We are not planning further verification on our side. If you decide to pursue this and need the three changes above, please say so. Until then, RTT/2 remains the only supported microsecond-scale method, and one-way cross-card latency has no supported measurement path.

   On the 507018 failure — separate issue, and we need more data

   Please treat this as unrelated to the timestamp question. 507018 is a generic host-side code (aclrtSynchronizeStreamWithTimeout failed) that masks several distinct on-device mechanisms, so it cannot be classified from the host error alone. Could you re-run with the device log redirected and attach it:

   mkdir -p <outdir>/ascend
   export ASCEND_PROCESS_LOG_PATH=<outdir>/ascend
   # then attach $ASCEND_PROCESS_LOG_PATH/device-*/device-*.log

   Also useful: the error detail: / orch_error_code= / sched_error_code= / sub_class= fields from the host log. The distinguishing signatures are an allocator/pool FATAL: ... Deadlock, a Timeout (N cycles): producer/consumers ..., log_stall_diagnostics, or only HandleTaskTimeout / kill aicpu-sd — the last of which indicates a long or stalled op rather than a proven deadlock. Whether that specific PyPTO / runtime / PTO-ISA / PTOAS combination is a supported pairing needs a separate check against the release matrix.
3. Mewtwo-Jieyu commented on Sep 22, 2026

   

   Mewtwo-Jieyu

   on Sep 22, 2026

   Author

   More actions

   Thank you — the reply settles the measurement questions for us, and the algebra (RTT/2 exact, one-way not identifiable, the per-device (T_A - R_A) - (T_B - R_B) term being indistinguishable from o) is clear.

   Clock-anchor changes: yes, please. We would use the host-anchored correlation as an independent check on our fitted offsets (3-6 us scale), not as a precision one-way measurement — so the +/-2 us hard bound is the right target for us. If you proceed, all three changes are welcome:

   1. Spin on aclrtQueryEventStatus instead of the blocking aclrtSynchronizeEvent (the ~15 us wakeup-dominated bracket is the current blocker);
   2. Move the aclrtEventGetTimestamp call after h1;
   3. Raise kClockAnchorSamplesPerPosition and intersect the per-sample intervals rather than averaging.

   We understand the offline tools no longer consume clock_anchors, so we will parse clock_anchors.samples[] (including uncertainty_ns) ourselves — no tooling work is needed on your side beyond the three changes above. We will also state in our own notes that this bound cannot resolve 0.3 us-scale differences such as the corrected 12.8 vs 12.5 us columns.

   507018: reproduction with device logs attached. We re-ran the probe per your instructions, with ASCEND_PROCESS_LOG_PATH redirected, on a previously idle card group:

   • Same pinned stack as the issue's A/B note: PyPTO 4fde258f, loaded runtime c540572d, PTO-ISA 5a4f74cb, PTOAS 0.57.
   • Scripts byte-identical to the published package (tarball SHA-256 e24340122f13d7c0545b96f29b53bc1fb788eef059530436342ecd13bd39026f).
   • Devices 4,5,6,7; the run completed 10 dispatches, then at run_id=22 on dev=6 raised the same chain: finalize_native_run failed with code 507018 -> lane poisoned -> release_domain(allocation_id=0) failed on 4/4 chips -> comm_release_domain_windows failed with code -1 -> exit code 139 (SIGSEGV).

   Device-log signatures (from $ASCEND_PROCESS_LOG_PATH/debug/device-6/, times UTC+8):

   • 15:27:49 — chip_swimlane_aicpu_complete_task failed for task 0x100000001 / 0x100000004 (Core 29 / Core 32, scheduler_completion.cpp:268)
   • 15:28:04 — HandleTaskTimeout: op simpler_aicpu_exec, serialNo=22, stream_id=43, task_id=21, elapsed 45.3 s vs the 45 s op-execute timeout; tsdaemon kills aicpu-sd
   • None of the four devices show an allocator/pool FATAL: ... Deadlock, a Timeout (N cycles): producer/consumers cycle, or log_stall_diagnostics.

   By your classification guide this lands in the "long or stalled op" bucket rather than a proven deadlock. Two additional observations we could not classify ourselves:

   1. The error detail: / orch_error_code= / sched_error_code= / sub_class= fields do not appear in our host log at default verbosity; the full host traceback is in the attachment instead. If there is a runtime log level that emits them, we can re-run with it.
   2. chip_swimlane_collector_aicpu.cpp logs ERROR-level free_queue is empty during init! lines on all four devices during every collector (re-)init, including ones that precede dispatches that succeed. Is that expected noise for an L3 capture?

   The release-matrix question from the issue still stands: is the PyPTO 4fde258f + runtime c540572d + PTO-ISA 5a4f74c + PTOAS 0.57 pairing supported for this probe?

   Attachment: attachment-507018-20260922.tar.gz
   SHA-256: 249805fe673f58a6f2f04848e340e480f1090cb2a8ff99d2a2377d3b374f4feb

   Contents: host run/driver logs (personal absolute root replaced by <ROOT>), exit code, npu-smi before/after, and the full ascend/run/ + ascend/debug/ device and plog files (unmodified; container-internal PIDs kept for cross-log correlation).

   attachment-507018-20260922.tar.gz
4. ChaoZheng109 commented on Oct 16, 2026

   

   ChaoZheng109

   on Oct 16, 2026

   Collaborator

   More actions

   The clock-domain question has been clarified. For the separate 507018 failure, there are currently three possible explanations:

   1. A long-running operation: execution was still progressing but exceeded the 45-second op-execute limit.
   2. An intermittent execution stall: a kernel, communication wait, or scheduling path stopped making progress and was eventually terminated by the watchdog. The logs do not establish a deadlock.
   3. A runtime lifecycle or teardown defect: collector cleanup/reinitialization may affect a subsequent run, or error-path teardown may mishandle the initial timeout, leading to the communication-window release failures and SIGSEGV.

   These possibilities are not mutually exclusive. In particular, an execution timeout could expose a separate cleanup defect.

   We could not reproduce the reported failure with the current mainline collective cases and matching pinned toolchain on A3. This differs from the original 910B2 setup with custom probes, so it does not establish that the original failure has been fixed. Successful execution also does not validate teardown after a timeout.

   We are closing this issue now that the timestamp question has been answered. If the runtime failure persists on current mainline, please track it in a separate issue with the exact versions, reproducer, and host/device logs.
5. ChaoZheng109

   closed this as completedon Oct 16, 2026