RR(S): 8026334: hs_err improvement: Print elapsed time in a humanly readable format

[Kevin Walls]

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
>>
>>
>>
>

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-runtime-dev/attachments/20140401/38020282/attachment-0001.html>