Skip to content

Commit c206575

Browse files
erikdarlingdataerikdarlingdata
authored
Merge pull request #338 from erikdarlingdata/fix/udf-timing-units
Fix UDF timing units: microseconds to milliseconds
2 parents ed9c6ae + 48c0910 commit c206575

8 files changed

Lines changed: 24 additions & 28 deletions

File tree

‎Dashboard/Controls/PlanViewerControl.xaml.cs‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -688,17 +688,17 @@ private void ShowPropertiesPanel(PlanNode node)
688688

689689
// Timing
690690
if (node.ActualElapsedMs > 0 || node.ActualCPUMs > 0
691-
|| node.UdfCpuTimeUs > 0 || node.UdfElapsedTimeUs > 0)
691+
|| node.UdfCpuTimeMs > 0 || node.UdfElapsedTimeMs > 0)
692692
{
693693
AddPropertySection("Actual Timing");
694694
if (node.ActualElapsedMs > 0)
695695
AddPropertyRow("Elapsed Time", $"{node.ActualElapsedMs:N0} ms");
696696
if (node.ActualCPUMs > 0)
697697
AddPropertyRow("CPU Time", $"{node.ActualCPUMs:N0} ms");
698-
if (node.UdfElapsedTimeUs > 0)
699-
AddPropertyRow("UDF Elapsed", $"{node.UdfElapsedTimeUs:N0} us");
700-
if (node.UdfCpuTimeUs > 0)
701-
AddPropertyRow("UDF CPU", $"{node.UdfCpuTimeUs:N0} us");
698+
if (node.UdfElapsedTimeMs > 0)
699+
AddPropertyRow("UDF Elapsed", $"{node.UdfElapsedTimeMs:N0} ms");
700+
if (node.UdfCpuTimeMs > 0)
701+
AddPropertyRow("UDF CPU", $"{node.UdfCpuTimeMs:N0} ms");
702702
}
703703

704704
// I/O

‎Dashboard/Models/PlanModels.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -272,8 +272,8 @@ public class PlanNode
272272
public string? ActionColumn { get; set; }
273273
public long ActualSegmentReads { get; set; }
274274
public long ActualSegmentSkips { get; set; }
275-
public long UdfCpuTimeUs { get; set; }
276-
public long UdfElapsedTimeUs { get; set; }
275+
public long UdfCpuTimeMs { get; set; }
276+
public long UdfElapsedTimeMs { get; set; }
277277

278278
// XSD gap: RelOp-level metadata
279279
public bool GroupExecuted { get; set; }

‎Dashboard/Services/PlanAnalyzer.cs‎

Lines changed: 3 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -221,15 +221,13 @@ private static void AnalyzeNode(PlanNode node, PlanStatement stmt)
221221
}
222222

223223
// Rule 4: UDF timing — any node spending time in UDFs (actual plans)
224-
if (node.UdfCpuTimeUs > 0 || node.UdfElapsedTimeUs > 0)
224+
if (node.UdfCpuTimeMs > 0 || node.UdfElapsedTimeMs > 0)
225225
{
226-
var cpuMs = node.UdfCpuTimeUs / 1000.0;
227-
var elapsedMs = node.UdfElapsedTimeUs / 1000.0;
228226
node.Warnings.Add(new PlanWarning
229227
{
230228
WarningType = "UDF Execution",
231-
Message = $"Scalar UDF executing on this operator. UDF elapsed: {elapsedMs:F1}ms, UDF CPU: {cpuMs:F1}ms",
232-
Severity = elapsedMs >= 1000 ? PlanWarningSeverity.Critical : PlanWarningSeverity.Warning
229+
Message = $"Scalar UDF executing on this operator. UDF elapsed: {node.UdfElapsedTimeMs:N0}ms, UDF CPU: {node.UdfCpuTimeMs:N0}ms",
230+
Severity = node.UdfElapsedTimeMs >= 1000 ? PlanWarningSeverity.Critical : PlanWarningSeverity.Warning
233231
});
234232
}
235233

‎Dashboard/Services/ShowPlanParser.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1179,8 +1179,8 @@ private static PlanNode ParseRelOp(XElement relOpEl)
11791179
node.ActualExecutionMode = actualExecMode;
11801180
node.ActualSegmentReads = totalSegmentReads;
11811181
node.ActualSegmentSkips = totalSegmentSkips;
1182-
node.UdfCpuTimeUs = totalUdfCpu;
1183-
node.UdfElapsedTimeUs = maxUdfElapsed;
1182+
node.UdfCpuTimeMs = totalUdfCpu;
1183+
node.UdfElapsedTimeMs = maxUdfElapsed;
11841184

11851185
// Store per-thread data for parallel skew analysis
11861186
foreach (var thread in runtimeEl.Elements(Ns + "RunTimeCountersPerThread"))

‎Lite/Controls/PlanViewerControl.xaml.cs‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -698,17 +698,17 @@ private void ShowPropertiesPanel(PlanNode node)
698698

699699
// Timing
700700
if (node.ActualElapsedMs > 0 || node.ActualCPUMs > 0
701-
|| node.UdfCpuTimeUs > 0 || node.UdfElapsedTimeUs > 0)
701+
|| node.UdfCpuTimeMs > 0 || node.UdfElapsedTimeMs > 0)
702702
{
703703
AddPropertySection("Actual Timing");
704704
if (node.ActualElapsedMs > 0)
705705
AddPropertyRow("Elapsed Time", $"{node.ActualElapsedMs:N0} ms");
706706
if (node.ActualCPUMs > 0)
707707
AddPropertyRow("CPU Time", $"{node.ActualCPUMs:N0} ms");
708-
if (node.UdfElapsedTimeUs > 0)
709-
AddPropertyRow("UDF Elapsed", $"{node.UdfElapsedTimeUs:N0} us");
710-
if (node.UdfCpuTimeUs > 0)
711-
AddPropertyRow("UDF CPU", $"{node.UdfCpuTimeUs:N0} us");
708+
if (node.UdfElapsedTimeMs > 0)
709+
AddPropertyRow("UDF Elapsed", $"{node.UdfElapsedTimeMs:N0} ms");
710+
if (node.UdfCpuTimeMs > 0)
711+
AddPropertyRow("UDF CPU", $"{node.UdfCpuTimeMs:N0} ms");
712712
}
713713

714714
// I/O

‎Lite/Models/PlanModels.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -272,8 +272,8 @@ public class PlanNode
272272
public string? ActionColumn { get; set; }
273273
public long ActualSegmentReads { get; set; }
274274
public long ActualSegmentSkips { get; set; }
275-
public long UdfCpuTimeUs { get; set; }
276-
public long UdfElapsedTimeUs { get; set; }
275+
public long UdfCpuTimeMs { get; set; }
276+
public long UdfElapsedTimeMs { get; set; }
277277

278278
// XSD gap: RelOp-level metadata
279279
public bool GroupExecuted { get; set; }

‎Lite/Services/PlanAnalyzer.cs‎

Lines changed: 3 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -221,15 +221,13 @@ private static void AnalyzeNode(PlanNode node, PlanStatement stmt)
221221
}
222222

223223
// Rule 4: UDF timing — any node spending time in UDFs (actual plans)
224-
if (node.UdfCpuTimeUs > 0 || node.UdfElapsedTimeUs > 0)
224+
if (node.UdfCpuTimeMs > 0 || node.UdfElapsedTimeMs > 0)
225225
{
226-
var cpuMs = node.UdfCpuTimeUs / 1000.0;
227-
var elapsedMs = node.UdfElapsedTimeUs / 1000.0;
228226
node.Warnings.Add(new PlanWarning
229227
{
230228
WarningType = "UDF Execution",
231-
Message = $"Scalar UDF executing on this operator. UDF elapsed: {elapsedMs:F1}ms, UDF CPU: {cpuMs:F1}ms",
232-
Severity = elapsedMs >= 1000 ? PlanWarningSeverity.Critical : PlanWarningSeverity.Warning
229+
Message = $"Scalar UDF executing on this operator. UDF elapsed: {node.UdfElapsedTimeMs:N0}ms, UDF CPU: {node.UdfCpuTimeMs:N0}ms",
230+
Severity = node.UdfElapsedTimeMs >= 1000 ? PlanWarningSeverity.Critical : PlanWarningSeverity.Warning
233231
});
234232
}
235233

‎Lite/Services/ShowPlanParser.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1179,8 +1179,8 @@ private static PlanNode ParseRelOp(XElement relOpEl)
11791179
node.ActualExecutionMode = actualExecMode;
11801180
node.ActualSegmentReads = totalSegmentReads;
11811181
node.ActualSegmentSkips = totalSegmentSkips;
1182-
node.UdfCpuTimeUs = totalUdfCpu;
1183-
node.UdfElapsedTimeUs = maxUdfElapsed;
1182+
node.UdfCpuTimeMs = totalUdfCpu;
1183+
node.UdfElapsedTimeMs = maxUdfElapsed;
11841184

11851185
// Store per-thread data for parallel skew analysis
11861186
foreach (var thread in runtimeEl.Elements(Ns + "RunTimeCountersPerThread"))

0 commit comments

Comments
 (0)