RR(S): 8026334: hs_err improvement: Print elapsed time in a humanly readable format
Kevin Walls
kevin.walls at oracle.com
Wed Apr 2 14:35:37 UTC 2014
Great, thanks Coleen, thanks Dmitry!
Regards
Kevin
On 02/04/14 15:34, Dmitry Samersoff wrote:
> Kevin,
>
> Looks good for me.
>
> -Dmitry
>
> On 2014-04-02 18:27, Kevin Walls wrote:
>> Hi Dmitry, all,
>>
>> So we exchanged emails off the list about the accuracy, and are content
>> to keep the ints for the calculations. They can be re-multiplied to
>> accurately reconstruct the int value of the "elapsed time" that we
>> print, which we did as an exercise. Any accuracy concerns after the
>> initial cast from double to int, which we already do, don't seem
>> relevant within the expected uptime of most life forms, let alone
>> processes[1].
>>
>> It is with formatting changes alone that we refresh the webrev:
>>
>> http://cr.openjdk.java.net/~kevinw/8026334/webrev.01/
>>
>> Thanks
>> Kevin
>>
>> [1] that's a forward-looking statement, should come with a disclaimer.
>>
>>
>>
>> On 02/04/14 08:46, Dmitry Samersoff wrote:
>>> Kevin,
>>>
>>> 1. It's better to use double for arithmetics and convert it to int on
>>> printing.
>>>
>>>
>>> 2. we probably can get rid of intermittent variables
>>> day_secs, hour_secs, minute_secs
>>>
>>>
>>> 3. I would prefer to have constants as all-caps #defines outside of
>>> function definition or (if you or Coleen disagree with it) at least
>>> moved to ll.935 with empty line before and after it.
>>>
>>> -Dmitry
>>>
>>> On 2014-04-02 00:53, Kevin Walls wrote:
>>>> Thanks Coleen -
>>>>
>>>> Here's an update, the constants are good, here's an attempt to use
>>>> constants and keep it not too verbose:
>>>>
>>>> http://cr.openjdk.java.net/~kevinw/8026334/webrev.01/
>>>>
>>>> Thanks
>>>> Kevin & Masato
>>>>
>>>>
>>>> On 26/03/14 23:44, Coleen Phillimore wrote:
>>>>> Can you make these expressions into a variable for the
>>>>> calculations? IE.
>>>>> 86400 = seconds_in_a_day
>>>>> 3600 = seconds_in_an_hour
>>>>> 60 = seconds_in_a_minute
>>>>>
>>>>> and then have
>>>>> eldays * 86400 be something like day_seconds
>>>>>
>>>>> Thanks - it would be nice if these numbers only appear once each.
>>>>> Coleen
>>>>> On 3/26/14 7:08 PM, Kevin Walls wrote:
>>>>>> Hi,
>>>>>>
>>>>>> I'd like to get a review of this change:
>>>>>>
>>>>>> It's adding a human-readable breakdown of the elapsed time, which is
>>>>>> currently printed in raw seconds in the hs_err file (it's the last
>>>>>> item printed).
>>>>>>
>>>>>> This is on behalf of Masato Yoshido who has worked on it. Further
>>>>>> details below, including a method that was used for manual testing.
>>>>>>
>>>>>> bug:
>>>>>> https://bugs.openjdk.java.net/browse/JDK-8026334
>>>>>>
>>>>>> webrev:
>>>>>> http://cr.openjdk.java.net/~kevinw/8026334/webrev.00/
>>>>>>
>>>>>> Many thanks,
>>>>>> Kevin
>>>>>> Masato
>>>>>>
>>>>>>
>>>>>> [Change details]
>>>>>>
>>>>>> - Time format will change as follows:
>>>>>>
>>>>>> (from)
>>>>>> elapsed time: %d seconds
>>>>>>
>>>>>> (to)
>>>>>> elapsed time: %d seconds (%dd %dh %dm %ds)
>>>>>>
>>>>>> - The reason why I leave the original elapsed time format is:
>>>>>> -- We don’t need to remove the original format. If we remove it,
>>>>>> ones
>>>>>> who want time information in seconds need to calculate from
>>>>>> day-,
>>>>>> hour-, minute- and second-parts.
>>>>>>
>>>>>> - There is no code doing exactly the same thing. Another code to which
>>>>>> we might be able to apply calculation similar to this conversion is
>>>>>> the GC log with -XX:+PrintGCTimeStamps. However, the elapsed time
>>>>>> in GC log is a floating point number, while the time in hs_err log
>>>>>> is an integer since there is a problem when %f is used in printf
>>>>>> on Linux platform (See comments in os::print_date_and_time
>>>>>> function).
>>>>>> Therefore, the same code as this cannot simply be share with GC
>>>>>> log.
>>>>>>
>>>>>>
>>>>>> [Test]
>>>>>>
>>>>>> (1) Tested only part of code of elapsed time calculation and printing.
>>>>>>
>>>>>> --- test_print_time.cpp ---
>>>>>> #include <stdio.h>
>>>>>> #include <stdlib.h>
>>>>>> #include <limits.h>
>>>>>>
>>>>>> void print_date_and_time(double t) {
>>>>>> int eltime = (int)t; // elapsed time in seconds
>>>>>> int eldays, elhours, elminutes, elseconds; // for printing elapsed
>>>>>> time in a humanly readable format
>>>>>> eldays = eltime / 86400;
>>>>>> elhours = (eltime - eldays * 86400) / 3600;
>>>>>> elminutes = (eltime - eldays * 86400 - elhours * 3600) / 60;
>>>>>> elseconds = (eltime - eldays * 86400 - elhours * 3600 - elminutes *
>>>>>> 60);
>>>>>> printf("elapsed time: %d seconds (%dd %dh %dm %ds)", eltime,
>>>>>> eldays, elhours, elminutes, elseconds);
>>>>>> printf("\n");
>>>>>> }
>>>>>>
>>>>>> int main(int argc, char *argv[]) {
>>>>>> print_date_and_time((double)86399);
>>>>>> print_date_and_time((double)86400);
>>>>>> print_date_and_time((double)86401);
>>>>>> printf("\n");
>>>>>>
>>>>>> print_date_and_time((double)86399.999);
>>>>>> print_date_and_time((double)86400.999);
>>>>>> print_date_and_time((double)86401.999);
>>>>>> printf("\n");
>>>>>>
>>>>>> print_date_and_time((double)(-86399));
>>>>>> print_date_and_time((double)(-86400));
>>>>>> print_date_and_time((double)(-86401));
>>>>>> printf("\n");
>>>>>>
>>>>>> print_date_and_time((double)INT_MAX);
>>>>>> print_date_and_time((double)(INT_MAX+1));
>>>>>> print_date_and_time((double)UINT_MAX);
>>>>>> }
>>>>>> ---
>>>>>>
>>>>>> --- Run the test program
>>>>>> $ ./test_print_time
>>>>>> elapsed time: 86399 seconds (0d 23h 59m 59s)
>>>>>> elapsed time: 86400 seconds (1d 0h 0m 0s)
>>>>>> elapsed time: 86401 seconds (1d 0h 0m 1s)
>>>>>>
>>>>>> elapsed time: 86399 seconds (0d 23h 59m 59s)
>>>>>> elapsed time: 86400 seconds (1d 0h 0m 0s)
>>>>>> elapsed time: 86401 seconds (1d 0h 0m 1s)
>>>>>>
>>>>>> elapsed time: -86399 seconds (0d -23h -59m -59s)
>>>>>> elapsed time: -86400 seconds (-1d 0h 0m 0s)
>>>>>> elapsed time: -86401 seconds (-1d 0h 0m -1s)
>>>>>>
>>>>>> elapsed time: 2147483647 seconds (24855d 3h 14m 7s)
>>>>>> elapsed time: -2147483648 seconds (-24855d -3h -14m -8s)
>>>>>> elapsed time: -2147483648 seconds (-24855d -3h -14m -8s)
>>>>>> ---
>>>>>>
>>>>>>
>>>>>> (2) Tested using a JNI program causing Segmentation Violation.
>>>>>> Tested on the following platforms:
>>>>>> solaris sparcv9
>>>>>> solaris x64
>>>>>> linux x86
>>>>>> linux x64
>>>>>> windows x86
>>>>>> windows x64
>>>>>> macosx x64
>>>>>> hs_err_pid<pid>.log file was successfully generated with expected
>>>>>> “elapsed time” line on each platform.
>>>>>>
>>>>>>
>>>>>> --- TestCrash.java ---
>>>>>> public class TestCrash {
>>>>>> static {
>>>>>> System.loadLibrary("testcrash");
>>>>>> }
>>>>>>
>>>>>> public static native void crash();
>>>>>>
>>>>>> public static void main(String[] args) {
>>>>>> try {
>>>>>> Thread.sleep(61000);
>>>>>> } catch (InterruptedException e) {
>>>>>> e.printStackTrace();
>>>>>> }
>>>>>> crash();
>>>>>> }
>>>>>> }
>>>>>> ---
>>>>>>
>>>>>> --- TestCrash.c ---
>>>>>> #include <jni.h>
>>>>>>
>>>>>> #ifdef __cplusplus
>>>>>> extern "C" {
>>>>>> #endif
>>>>>> /*
>>>>>> * Class: TestCrash
>>>>>> * Method: crash
>>>>>> * Signature: ()V
>>>>>> */
>>>>>> JNIEXPORT void JNICALL Java_TestCrash_crash(JNIEnv *env, jclass cls) {
>>>>>> const char *p = "Hello, world!";
>>>>>> *(char *)p = 'a';
>>>>>> }
>>>>>>
>>>>>> #ifdef __cplusplus
>>>>>> }
>>>>>> #endif
>>>>>> ---
>>>>>>
>>>>>>
>>>>>> Thanks and best regards,
>>>>>> Masato
>>>>>>
>>>>>>
>>>>>>
>
More information about the hotspot-runtime-dev
mailing list