diff --git a/include/gpufl/backends/nvidia/cupti_activity_callbacks.cpp b/include/gpufl/backends/nvidia/cupti_activity_callbacks.cpp index 883734b..db0d38b 100644 --- a/include/gpufl/backends/nvidia/cupti_activity_callbacks.cpp +++ b/include/gpufl/backends/nvidia/cupti_activity_callbacks.cpp @@ -239,37 +239,49 @@ void CUPTIAPI CuptiBackend::BufferCompleted(CUcontext context, // are in CUPTI's clock domain - convert to // wall using the same baseCpuNs/baseCuptiTs // delta the rest of BufferCompleted uses. - // start == end == 0 is a valid CUPTI signal - // for "couldn't collect timing"; we honor it - // by emitting duration=0 rather than dropping - // the row (the graph_id is still useful - // attribution). + // + // start == end == 0 is CUPTI's "couldn't + // collect timing" signal. v1 emitted those as + // duration=0 rows to keep the graph_id + // attribution, but on Windows/Blackwell a + // CUDA-graph replay loop returns MOSTLY zeroed + // records (observed live: 61 of 63), and a + // start_ns=0 row renders at epoch 0 and wrecks + // the dashboard timeline bounds - so they are + // dropped now, like every other + // invalid-timestamp activity record. auto* g = reinterpret_cast< const CUpti_ActivityGraphTrace2*>(record); - int64_t start_wall = 0; - int64_t dur = 0; - if (g->start != 0 || g->end != 0) { - start_wall = static_cast(g->start) - - static_cast(baseCuptiTs) + - baseCpuNs; + constexpr int64_t kMaxTsSkewNs = + 3'600'000'000'000LL; // 1 hour + const int64_t start_wall = + static_cast(g->start) - + static_cast(baseCuptiTs) + baseCpuNs; + if (g->start == 0 || g->end < g->start || + start_wall < baseCpuNs - kMaxTsSkewNs || + start_wall > + detail::GetTimestampNs() + kMaxTsSkewNs) { + GFL_LOG_DEBUG( + "[CuptiBackend] dropping graph-trace " + "record with invalid timestamps corr=", + g->correlationId, " start=", g->start, + " end=", g->end); + } else { const int64_t end_wall = static_cast(g->end) - static_cast(baseCuptiTs) + baseCpuNs; - dur = end_wall - start_wall; - if (dur < 0) dur = 0; // clock-skew guard + ActivityRecord out{}; + out.type = TraceType::GRAPH_LAUNCH; + out.cpu_start_ns = start_wall; + out.duration_ns = end_wall - start_wall; + out.device_id = g->deviceId; + out.stream = g->streamId; + out.corr_id = g->correlationId; + out.graph_id = g->graphId; + g_monitorBuffer.Push(out); + backend->graph_activity_emitted_.fetch_add( + 1, std::memory_order_relaxed); } - - ActivityRecord out{}; - out.type = TraceType::GRAPH_LAUNCH; - out.cpu_start_ns = start_wall; - out.duration_ns = dur; - out.device_id = g->deviceId; - out.stream = g->streamId; - out.corr_id = g->correlationId; - out.graph_id = g->graphId; - g_monitorBuffer.Push(out); - backend->graph_activity_emitted_.fetch_add( - 1, std::memory_order_relaxed); } else if (record->kind == CUPTI_ACTIVITY_KIND_MEMORY2) { // F3: cudaMalloc / cudaFree / cudaMallocAsync / diff --git a/include/gpufl/backends/nvidia/kernel_launch_handler.cpp b/include/gpufl/backends/nvidia/kernel_launch_handler.cpp index 350367a..b025d45 100644 --- a/include/gpufl/backends/nvidia/kernel_launch_handler.cpp +++ b/include/gpufl/backends/nvidia/kernel_launch_handler.cpp @@ -492,15 +492,32 @@ bool KernelLaunchHandler::handleActivityRecord(const CUpti_Activity* record, // CUPTI occasionally delivers a kernel activity record with unfilled // timestamps (start == 0, often end == 0 too). A real kernel's CUPTI start - // is always nonzero, so start == 0 means "no GPU timing". Converting it - // through the wall-clock anchor (baseCpuNs + (0 - baseCuptiTs)) yields a - // time at system boot - days before the session - which then sorts to the - // very top of the UI's kernel list with a bogus absolute start and 0 - // duration. Drop these; they carry no usable timeline data. - if (k->start == 0 || k->end < k->start) { + // is always nonzero, so start == 0 means "no GPU timing". Stream-capture + // launches (CUDA graph capture) hit this en masse - captured launches are + // recorded, not executed, so CUPTI emits their records with zeroed + // timestamps (~2k in one capture pass). Converting one through the + // wall-clock anchor (baseCpuNs + (0 - baseCuptiTs)) yields a time at + // system boot - days before the session. The plausibility window catches + // the opposite corruption too: a garbage-huge CUPTI timestamp whose + // converted wall time lands far past "now" (observed live on a memcpy + // record around CUDA-graph replays - same disease, other direction). + // Drop these; they carry no usable timeline data. The drop must also take + // the launch meta with it (KERNEL_META_DISCARD) or drainSyntheticKernels + // resurrects the launch as a synthetic row whose "duration" is the host + // dispatch gap. + constexpr int64_t kMaxTsSkewNs = 3'600'000'000'000LL; // 1 hour + const int64_t wallStartNs = + baseCpuNs + static_cast(k->start - baseCuptiTs); + if (k->start == 0 || k->end < k->start || + wallStartNs < baseCpuNs - kMaxTsSkewNs || + wallStartNs > detail::GetTimestampNs() + kMaxTsSkewNs) { GFL_LOG_DEBUG("[KernelLaunchHandler] dropping kernel activity with " "invalid timestamps corr=", k->correlationId, " start=", k->start, " end=", k->end); + ActivityRecord drop{}; + drop.type = TraceType::KERNEL_META_DISCARD; + drop.corr_id = k->correlationId; + g_monitorBuffer.Push(drop); return false; } @@ -526,7 +543,7 @@ bool KernelLaunchHandler::handleActivityRecord(const CUpti_Activity* record, std::snprintf(out.name, sizeof(out.name), "%.*s", static_cast(sizeof(out.name) - 1), kernelName); - out.cpu_start_ns = baseCpuNs + static_cast(k->start - baseCuptiTs); + out.cpu_start_ns = wallStartNs; out.duration_ns = static_cast(k->end - k->start); out.dyn_shared = k->dynamicSharedMemory; out.static_shared = k->staticSharedMemory; diff --git a/include/gpufl/backends/nvidia/mem_transfer_handler.cpp b/include/gpufl/backends/nvidia/mem_transfer_handler.cpp index c7fcc75..831229e 100644 --- a/include/gpufl/backends/nvidia/mem_transfer_handler.cpp +++ b/include/gpufl/backends/nvidia/mem_transfer_handler.cpp @@ -242,16 +242,37 @@ void MemTransferHandler::handle(CUpti_CallbackDomain domain, bool MemTransferHandler::handleActivityRecord(const CUpti_Activity* record, int64_t baseCpuNs, uint64_t baseCuptiTs) { + // Same invalid-timestamp drop the kernel handler applies. Observed live: a + // D2D memcpy around CUDA-graph replays arrived with a garbage-huge CUPTI + // timestamp whose converted wall time sat ~95 years past the session and + // exploded the dashboard timeline bounds; zeroed timestamps land at system + // boot the same way. The drop takes the API meta with it + // (KERNEL_META_DISCARD) so the collector's join map doesn't hold it forever. + constexpr int64_t kMaxTsSkewNs = 3'600'000'000'000LL; // 1 hour + if (record->kind == CUPTI_ACTIVITY_KIND_MEMCPY || record->kind == CUPTI_ACTIVITY_KIND_MEMCPY2) { const auto* m = reinterpret_cast(record); + const int64_t wallStartNs = + baseCpuNs + static_cast(m->start - baseCuptiTs); + if (m->start == 0 || m->end < m->start || + wallStartNs < baseCpuNs - kMaxTsSkewNs || + wallStartNs > detail::GetTimestampNs() + kMaxTsSkewNs) { + GFL_LOG_DEBUG("[MemTransferHandler] dropping memcpy activity with " + "invalid timestamps corr=", m->correlationId, + " start=", m->start, " end=", m->end); + ActivityRecord drop{}; + drop.type = TraceType::KERNEL_META_DISCARD; + drop.corr_id = m->correlationId; + g_monitorBuffer.Push(drop); + return false; + } ActivityRecord out{}; out.device_id = m->deviceId; out.stream = static_cast(m->streamId); out.type = TraceType::MEMCPY; out.corr_id = m->correlationId; - out.cpu_start_ns = - baseCpuNs + static_cast(m->start - baseCuptiTs); + out.cpu_start_ns = wallStartNs; out.duration_ns = static_cast(m->end - m->start); out.bytes = m->bytes; out.copy_kind = m->copyKind; @@ -268,13 +289,26 @@ bool MemTransferHandler::handleActivityRecord(const CUpti_Activity* record, if (record->kind == CUPTI_ACTIVITY_KIND_MEMSET) { const auto* m = reinterpret_cast(record); + const int64_t wallStartNs = + baseCpuNs + static_cast(m->start - baseCuptiTs); + if (m->start == 0 || m->end < m->start || + wallStartNs < baseCpuNs - kMaxTsSkewNs || + wallStartNs > detail::GetTimestampNs() + kMaxTsSkewNs) { + GFL_LOG_DEBUG("[MemTransferHandler] dropping memset activity with " + "invalid timestamps corr=", m->correlationId, + " start=", m->start, " end=", m->end); + ActivityRecord drop{}; + drop.type = TraceType::KERNEL_META_DISCARD; + drop.corr_id = m->correlationId; + g_monitorBuffer.Push(drop); + return false; + } ActivityRecord out{}; out.device_id = m->deviceId; out.stream = static_cast(m->streamId); out.type = TraceType::MEMSET; out.corr_id = m->correlationId; - out.cpu_start_ns = - baseCpuNs + static_cast(m->start - baseCuptiTs); + out.cpu_start_ns = wallStartNs; out.duration_ns = static_cast(m->end - m->start); out.bytes = m->bytes; std::snprintf(out.name, sizeof(out.name), "memset"); diff --git a/include/gpufl/core/monitor.cpp b/include/gpufl/core/monitor.cpp index f67ff92..4390554 100644 --- a/include/gpufl/core/monitor.cpp +++ b/include/gpufl/core/monitor.cpp @@ -242,6 +242,14 @@ struct RecordProcessor { case TraceType::SYNC_META: g_state.metadata.syncStackByCorr[rec.corr_id] = rec.stack_id; return true; + case TraceType::KERNEL_META_DISCARD: + // The CUPTI layer dropped this corr's activity record (invalid + // timestamps). Take the launch meta with it so + // drainSyntheticKernels can't resurrect the launch as a + // synthetic row with host-gap "duration" (a CUDA-graph capture + // pass is ~2k such drops in one go). + g_state.metadata.launchMetaByCorr.erase(rec.corr_id); + return true; default: break; } diff --git a/include/gpufl/core/trace_type.hpp b/include/gpufl/core/trace_type.hpp index cb0acec..af79da4 100644 --- a/include/gpufl/core/trace_type.hpp +++ b/include/gpufl/core/trace_type.hpp @@ -116,5 +116,15 @@ enum class TraceType : uint8_t { // stores corr_id->stack_id in g_syncStackByCorr and never emits this record. // Fields used on ActivityRecord: corr_id, stack_id. SYNC_META, + // KERNEL_META_DISCARD: pushed by KernelLaunchHandler / MemTransferHandler + // when an activity record is DROPPED for invalid timestamps. The collector + // erases the corr's launch-meta entry and emits nothing, so the dropped + // launch can't be resurrected by drainSyntheticKernels as a synthetic row + // whose "duration" is the host dispatch gap. Stream-capture launches + // (CUDA graph capture) hit the invalid-timestamp drop en masse - captured + // launches are recorded, not executed, so CUPTI emits their records with + // zeroed timestamps - and one capture pass would otherwise leave ~2k junk + // synthetic rows. Fields used on ActivityRecord: corr_id. + KERNEL_META_DISCARD, }; } \ No newline at end of file