Skip to content

Ensure ChromeTraceTest event timestamps are emitted in correct invervals #21911

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Nov 8, 2024
Merged

Ensure ChromeTraceTest event timestamps are emitted in correct invervals #21911

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
21 changes: 17 additions & 4 deletions compiler/test/dotty/tools/dotc/profile/ChromeTraceTest.scala
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -54,11 +54,11 @@ class ChromeTraceTest:
val testStart = System.nanoTime()
testTraceOutputs{ tracer =>
tracer.traceDurationEventStart(cat = "test1", name = "event1")
LockSupport.parkNanos(2.millis.toNanos)
sleep(2.millis)
tracer.traceDurationEventStart(cat = "test2", name = "event2", colour = "RED", pidSuffix = "pid-suffix")
LockSupport.parkNanos(4.millis.toNanos)
sleep(4.millis)
tracer.traceDurationEventEnd(cat = "test2", name = "event2")
LockSupport.parkNanos(8.millis.toNanos)
sleep(8.millis)
tracer.traceDurationEventEnd(cat = "test1", name = "event1", colour = "RED", pidSuffix = "pid-suffix")
}{
case """{"traceEvents":[""" ::
Expand Down Expand Up @@ -89,5 +89,18 @@ class ChromeTraceTest:
assertTrue(ts4 >= ts3 + 8.millis.toMicros)
case _ => fail("unreachable")
}
}
}

private def sleep(duration: FiniteDuration): Unit = {
// A bit of additional precautions to ensure we don't continue execution to early
// Both LockSuppport and Thread.sleep can return earlier then expected (depending on OS)
var remainingNanos = duration.toNanos
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Not sure if this is just a matter of personal taste or if it might make some difference in the actual behaviour:
Why not to compute the expected end time of sleep before the lop and then compare it with System.nanoTime in the loop?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It might behave differently. If we just sleep again using duration then in the worst case, we can sleep for 1.99x of expected time. To prevent that, we'd need to calculate the remaining time after pre-mature wake up anyway.

1 possible improvement could be potentially usage of TimeUnit.sleep(ofUnit: Long) but that would probably make it more complicate. Previously I though it's available only since JDK 9

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Of course I didn't mean sleeping twice with the same duration. I was thinking of something like

  private def sleep(duration: FiniteDuration): Unit = {
    // A bit of additional precautions to ensure we don't continue execution to early
    // Both LockSuppport and Thread.sleep can return earlier then expected (depending on OS)
    // var remainingNanos = duration.toNanos
    var currentNanos = System.nanoTime()
    val deadline = currentNanos + duration.toNanos
    while
      currentNanos = System.nanoTime()
      currentNanos < deadline
    do
      val remainingNanos = deadline - currentNanos
      val millis = NANOSECONDS.toMillis(remainingNanos)
      Thread.sleep(millis, (remainingNanos % 1.millis.toNanos).toInt)
  }

But maybe this doesn't make that much of a difference

val deadline = System.nanoTime() + remainingNanos
while
remainingNanos = deadline - System.nanoTime()
remainingNanos > 0
do
val millis = NANOSECONDS.toMillis(remainingNanos)
Thread.sleep(millis, (remainingNanos % 1.millis.toNanos).toInt)
}
}
Loading