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