RFR(S): hs_err elapsed time in seconds is not accurate enough
Kevin Walls
kevin.walls at oracle.com
Mon Mar 2 10:47:16 UTC 2020
Hi,
(s11y and runtime opinions both relevant)
A few times in the last month I've really wanted to compare the Events
logged in the hs_err file, and the time of the JVM's crash.
"elapsed time" in hs_err is only accurate to one second, and has been
since before jdk5 was created.
The diff below changes the format string and uses the non-rounded time
value (I don't see a need to change the other integer arithmetic here),
and we can enjoy hs_errs with detail like:
...
Time: Mon Mar 2 09:57:13 2020 UTC elapsed time: 5.490135 seconds (0d 0h
0m 5s)
...
Thanks
Kevin
/jdk/open$ hg diff
diff --git a/src/hotspot/share/runtime/os.cpp
b/src/hotspot/share/runtime/os.cpp
--- a/src/hotspot/share/runtime/os.cpp
+++ b/src/hotspot/share/runtime/os.cpp
@@ -1016,9 +1016,8 @@
}
double t = os::elapsedTime();
- // NOTE: It tends to crash after a SEGV if we want to printf("%f",...) in
- // Linux. Must be a bug in glibc ? Workaround is to round "t"
to int
- // before printf. We lost some precision, but who cares?
+ // NOTE: a crash using printf("%f",...) on Linux was historically
noted here
+ // (before the jdk5 repo was created).
int eltime = (int)t; // elapsed time in seconds
// print elapsed time in a human-readable format:
@@ -1029,7 +1028,7 @@
int elmins = (eltime - day_secs - hour_secs) / secs_per_min;
int minute_secs = elmins * secs_per_min;
int elsecs = (eltime - day_secs - hour_secs - minute_secs);
- st->print_cr(" elapsed time: %d seconds (%dd %dh %dm %ds)", eltime,
eldays, elhours, elmins, elsecs);
+ st->print_cr(" elapsed time: %f seconds (%dd %dh %dm %ds)", t,
eldays, elhours, elmins, elsecs);
}
More information about the serviceability-dev
mailing list