Skip to content

Commit 5773a39

Browse files
committed
trace2: fix child process time recording
Currently, we are recording child process times incorrectly for the performance format target. This change fixes that by: 1. Ensuring we're recording the absolute time in child_start messages for the performance format target, which we previously were not doing. 2. Ensures we do not conflate the absolute and relative times in child_exit, which we were previously doing.
1 parent 423241c commit 5773a39

File tree

3 files changed

+15
-9
lines changed

3 files changed

+15
-9
lines changed

src/shared/Core/Trace2.cs

Lines changed: 7 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -103,14 +103,14 @@ void WriteChildStart(DateTimeOffset startTime,
103103
/// <summary>
104104
/// Writes information related to exit of child process to trace writer.
105105
/// </summary>
106-
/// <param name="elapsedTime">Runtime of child process.</param>
106+
/// <param name="relativeTime">Runtime of child process.</param>
107107
/// <param name="pid">Id of exiting process.</param>
108108
/// <param name="code">Process exit code.</param>
109109
/// <param name="sid">The child process's session id.</param>
110110
/// <param name="filePath">Path of the file this method is called from.</param>
111111
/// <param name="lineNumber">Line number of file this method is called from.</param>
112112
void WriteChildExit(
113-
double elapsedTime,
113+
double relativeTime,
114114
int pid,
115115
int code,
116116
[System.Runtime.CompilerServices.CallerFilePath]
@@ -232,12 +232,13 @@ public void WriteChildStart(DateTimeOffset startTime,
232232
Classification = processClass,
233233
UseShell = useShell,
234234
Argv = procArgs,
235-
Depth = ProcessManager.Depth
235+
ElapsedTime = (DateTimeOffset.UtcNow - _applicationStartTime).TotalSeconds,
236+
Depth = ProcessManager.Depth,
236237
});
237238
}
238239

239240
public void WriteChildExit(
240-
double elapsedTime,
241+
double relativeTime,
241242
int pid,
242243
int code,
243244
string filePath = "",
@@ -262,7 +263,8 @@ public void WriteChildExit(
262263
Id = _childProcCounter,
263264
Pid = pid,
264265
Code = code,
265-
ElapsedTime = elapsedTime,
266+
ElapsedTime = (DateTimeOffset.UtcNow - _applicationStartTime).TotalSeconds,
267+
RelativeTime = relativeTime,
266268
Depth = ProcessManager.Depth
267269
});
268270
}

src/shared/Core/Trace2Message.cs

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -266,6 +266,8 @@ public class ChildStartMessage : Trace2Message
266266
[JsonProperty("argv")]
267267
public IList<string> Argv { get; set; }
268268

269+
public double ElapsedTime { get; set; }
270+
269271
public override string ToJson()
270272
{
271273
return JsonConvert.SerializeObject(this,
@@ -288,7 +290,7 @@ public override string ToPerformanceString()
288290

289291
protected override string BuildPerformanceSpan()
290292
{
291-
return EmptyPerformanceSpan;
293+
return $"| |{BuildTimeSpan(ElapsedTime)}| | ";
292294
}
293295

294296
protected override string GetEventMessage(Trace2FormatTarget formatTarget)
@@ -318,6 +320,8 @@ public class ChildExitMessage : Trace2Message
318320
public int Code { get; set; }
319321

320322
[JsonProperty("t_rel")]
323+
public double RelativeTime { get; set; }
324+
321325
public double ElapsedTime { get; set; }
322326

323327
public override string ToJson()
@@ -342,7 +346,7 @@ public override string ToPerformanceString()
342346

343347
protected override string BuildPerformanceSpan()
344348
{
345-
return $"| |{BuildTimeSpan(ElapsedTime)}| | ";
349+
return $"| |{BuildTimeSpan(ElapsedTime)}|{BuildTimeSpan(RelativeTime)}| ";
346350
}
347351

348352
protected override string GetEventMessage(Trace2FormatTarget formatTarget)
@@ -354,7 +358,7 @@ protected override string GetEventMessage(Trace2FormatTarget formatTarget)
354358
else
355359
sb.Append($"[{Id}]");
356360

357-
sb.Append($" pid:{Pid} code:{Code} elapsed:{ElapsedTime}");
361+
sb.Append($" pid:{Pid} code:{Code} elapsed:{RelativeTime}");
358362
return sb.ToString();
359363
}
360364
}

src/shared/TestInfrastructure/Objects/NullTrace.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -72,7 +72,7 @@ public void WriteChildStart(DateTimeOffset startTime,
7272
int lineNumber = 0) { }
7373

7474
public void WriteChildExit(
75-
double elapsedTime,
75+
double relativeTime,
7676
int pid,
7777
int code,
7878
string filePath = "",

0 commit comments

Comments
 (0)