RFR: 8072645: java.util.logging should use java.time to get more precise time stamps

Stephen Colebourne scolebourne at joda.org
Thu Feb 19 15:31:52 UTC 2015


A good improvement and ready to go from my perspective,
thanks
Stephen


On 19 February 2015 at 15:19, Daniel Fuchs <daniel.fuchs at oracle.com> wrote:
> On 18/02/15 12:11, Stephen Colebourne wrote:
>>
>> In LogRecord, the Javadoc of getInstant():
>> "Get event time."
>> could be
>> "Gets the instant that the event ocurred."
>
>
> done.
>
>> In LogRecord, the Javadoc of setInstant():
>> "Set event time."
>> could be
>> "Sets the instant that the event ocurred."
>> (matching change to @param)
>
>
> done.
>
>
>> I'd prefer to see the other methods in the class have their Javadoc
>> changed from "Get" to Gets" and from "Set" to "Sets" to conform with
>> Javadoc norms, but understand if this causes CCC issues.
>
>
> Agreed - but I will need to obtain a CCC approval for this change,
> and I'd prefer to leave the specdiff uncluttered.
> I will log an RFE for a doc cleanup.
>
>
>> In PlatformLogger.
>> There should be no need to assign to a static constant:
>>   private static final Clock systemUTC = Clock.systemUTC();
>> However, Clock.systemUTC() needs to be fixed:
>> https://bugs.openjdk.java.net/browse/JDK-8073394
>
>
> Ahah. I hadn't seen this RFE. Thanks for pointing it out.
> This RFE (JDK-8073394) won't need any CCC so it should be an easy
> quick fix. Given that, I agree that it's better to remove the
> static systemUTC fields (removed from PlatformLogger and LogRecord).
> I will also take care of JDK-8073394 later on then.
>
>
>> This
>>   ZonedDateTime zdt = ZonedDateTime.ofInstant(systemUTC.instant(),
>> zoneId);
>> can be replaced with
>>   ZonedDateTime zdt = ZonedDateTime.now(zoneId);
>
>
> done.
>
>> Again, the implementation of the better method isn't perfectly optimised.
>>
>> The default format used in String.format does not need to time-zone,
>> just the local date/time. As such, in theory a LocalDateTime could be
>> used. But, since the format can be changed by the user, a
>> ZonedDateTime is needed (probably not worth being clever here).
>
>
> Yes - that was my reasoning too. ZonedDateTime seems to be the
> more resilient to format changes.
>
>> Where you assign ZoneId.systemDefault() to a final instance variable,
>> it is being locked for the lifetime of that object. I cannot
>> immediately tell what the lifetime of the objects are. I also suspect
>> that few if any will want to change their time-zone half way through
>> logging.
>
>
> I don't think we should bother with this possibility.
>
> The PlatformLogger's simple logger may either never be
> released (if JUL is not used - meaning, if there is no user
> specified logging.properties file and if nobody calls
> LogManager.getLogManager()) - or it will be replaced by a
> plain logger - in which case the j.u.l.Formatter will
> be used - and the j.u.l.Formatter will usually have the
> same life-time than the Handler on which it is set.
> (usually, until reset() or readConfiguration() is called).
>
>
>> XMLFormatter has a reviewer's comment that will need to be removed
>> before committing.
>
>
> Will do before pushing. At the moment I'm still hoping it will catch
> the eye of an XML/DTD expert :-)
>
>> In LogRecordWithNanosAPI you check the instant contents rather than
>> just the instant:
>>   assertEquals(record.getInstant().getEpochSecond(),
>> record2.getInstant().getEpochSecond(),
>> "getInstant().getEpochSecond()");
>>   assertEquals(record.getInstant().getNano(),
>> record2.getInstant().getNano(), "getInstant().getNano()");
>>   assertEquals(record.getInstant().toEpochMilli(),
>> record2.getInstant().toEpochMilli(), "getInstant().toEpochMilli()");
>> could be
>>   assertEquals(record.getInstant(), record2.getInstant(), "getInstant()");
>> There are probably other instances of this point.
>
>
> Right. I'm not very motivated to change the LogRecord* tests.
> What happened is that I wrote these tests based on the use of
> LogRecord.setMillis/getMillis and
> LogRecord.getNanoAdjustment/setNanoAdjustment - and then had to
> update them when we decided to drop
> LogRecord.getNanoAdjustment/setNanoAdjustment and changed the
> implementation of getMillis/setMillis to work on top of instant.
>
> As a consequence, the test have probably become a bit more complex
> and cluttered than they would have been if I had written them
> directly against the later version of the API.
>
> However I believe they still do the job - I have been careful
> to add some additional tests to verify the new implementation of
> getMillis/setMillis - I don't believe I left any cracks.
>
> The important point is to verify the consistency of getMillis/getInstant
> and setMillis/setInstant as well as checking that nothing is lost
> in the serialization - I believe the tests are good enough in that
> respect.
>
>> Hope that helps
>
>
> It does! I am grateful :-)
>
> Here is the updated webrev.
> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/webrev.02/
>
> best regards,
>
> -- daniel
>
>
>> Stephen
>>
>>
>>
>> On 17 February 2015 at 19:33, Daniel Fuchs <daniel.fuchs at oracle.com>
>> wrote:
>>>
>>> Hi,
>>>
>>> Here is a new webrev - which should contain all the feedback received
>>> so far:
>>>
>>> #1 LogRecord uses serialPersistentFields for serialization, and
>>>     contains an Instant instead of the two fields millis +
>>>     nanoAdjustment.
>>> #2 getMillis/setMillis are deprecated, replaced by getInstant/setInstant
>>>     getNanoAdjustment/setNanoAdjustment have been dropped.
>>>
>>> [Thanks Peter for prototyping these 2 first changes!]
>>>
>>> #3 XMLFormatter uses ISO_INSTANT to print the instant in the date field.
>>>     new constructor has been dropped. printNanos property is renamed into
>>>     useInstant.
>>> #4 SimpleFormatter still uses ZonedDateTime - for compatibility and
>>>     flexibility and because it proved to be faster than Date [1].
>>> #5 Tests have been updated WRT to the changes above.
>>> #6 various doc tweaks compared to last webrev
>>>
>>> new webrev:
>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/webrev.01/
>>>
>>> specdiff updated in place (unfortunately the serial form does
>>> not show up):
>>>
>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/specdiff-logging-time/overview-summary.html
>>>
>>> best regards,
>>>
>>> -- daniel
>>>
>>> [1] benchmarks related to formatting the date:
>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/benchmarks.html
>>>
>>>
>>>
>>> On 16/02/15 20:24, Daniel Fuchs wrote:
>>>>
>>>>
>>>> Hi Stephen,
>>>>
>>>> Thanks again for your support and suggestions!
>>>>
>>>> On 14/02/15 14:03, Daniel Fuchs wrote:
>>>>>
>>>>>
>>>>> If I'm not mistaken the previous SimpleFormatter used to use
>>>>> java.util.Date
>>>>> and printed the time in the local time zone. I have tried to keep this
>>>>> behavior.
>>>>> I'm not sure we would want to change it to print the time in the UTC
>>>>> time zone
>>>>> by default. A lot of developers use logging for debugging - and when
>>>>> reading
>>>>> debug messages on the console I usually prefer to see the time in my
>>>>> own
>>>>> time zone.
>>>>>
>>>>> Would there be a more efficient way to keep the default formatting of
>>>>> the time
>>>>> in the SimpleFormatter?
>>>>
>>>>
>>>>
>>>> I spent part of the day reading the documentation & trying out the
>>>> various TemporalAccessors and DateTimeFormatters...
>>>>
>>>> I have also done some microbenchmark measurements (jmh) WRT
>>>> the performance  of formatting a date/time.
>>>> Results can be seen here [1]:
>>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/benchmarks.html
>>>>
>>>> What it shows is that when using String.format (as the SimpleFormatter
>>>> is specified to do), then using ZonedDateTime is actually an improvement
>>>> over using Date.
>>>>
>>>> Now that I have read a bit more about LocalDateTime, ZonedDateTime,
>>>> Date, and Instant, I do agree with you that for recording an event time,
>>>> printing the Instant is the better alternative.
>>>> However, since SimpleFormatter has always printed the local date,
>>>> I would tend to want to keep it that way.
>>>>
>>>> So I'm going to propose to keep using ZonedDateTime in
>>>> the SimpleFormatter, as I believe it's what gives it the maximum of
>>>> flexibility - WRT to using String.format (+ we will get some
>>>> boost as bonus by no longer using Date).
>>>> If you strongly feel that java.util.logging should offer a better
>>>> alternative - then maybe we should log an RFE to explore it?
>>>>
>>>> Things are - I believe - a bit different for the XMLFormatter.
>>>> First, the XMLFormatter is not specified to use String.format, so
>>>> it gives us a bit more flexibility.
>>>> In addition we already need to tweak the format in order to introduce
>>>> the new <nanos> element - (or should it be <nanoOfMilli> as Peter
>>>> suggested?).
>>>>
>>>> So for the XMLFormatter, and given the results of my
>>>> microbenchmark [1], here is what I would suggest:
>>>>
>>>> #1 rename the property printNanos into useInstant
>>>> #2 if useInstant is false, use the old code for formatting the
>>>>      date (the old appendISO8601() method) and omit the <nanos>
>>>>      element - so applications that specify useInstant=false should
>>>>      see the same formatting than before, without paying the
>>>>      performance cost that using ZonedDateTime would bring.
>>>> #3 if useInstant is absent - or not false, then we use the 'new'
>>>>      format. The <date> element will contain the instant printed
>>>>      using DateTimeFormatter.ISO_INSTANT, and the <nanos> element
>>>>      will be printed after <millis>
>>>>
>>>> Does that sound right? If so I will include these changes in my
>>>> next webrev, once I have digested the feedback sent by Peter :-)
>>>>
>>>> Best regards,
>>>>
>>>> -- daniel
>>>>
>>>> [1] microbenchmark:
>>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/benchmarks.html
>>>>
>>>>
>>>>>
>>>>>> (The webrev is broken wrt zones as it stores ZoneId.systemDefault() in
>>>>>> a
>>>>>> static constant, but that method depends on the mutable
>>>>>> TimeZone.getDefault() ).
>>>>>
>>>>>
>>>>>
>>>>> Would making it a final (non static) variable be better?
>>>>> I now wonder whether there should be a way to configure the time zone
>>>>> for
>>>>> an instance of SimpleFormatter (something like what I did with
>>>>> 'printNanos'
>>>>> for the XMLFormatter).
>>>>>
>>>>>> LogReecord.getInstantUTC() should be getInstant().
>>>>>>
>>>>>> (An Instant is fully defined as a concept, and it cannot be in or not
>>>>>> in
>>>>>> UTC).
>>>>>
>>>>>
>>>>>
>>>>> Right. Thanks for pointing that out.
>>>>>>
>>>>>>
>>>>>> In SimpleFormatter, you have {@code java.util.loggin} (missing a "g").
>>>>>
>>>>>
>>>>>
>>>>> Good catch.
>>>>>
>>>>>> In XMLFormatter, instead of using
>>>>>> DateTimeFormatter.ISO_LOCAL_DATE_TIME,
>>>>>> create a new instance of DateTimeFormatter that does not output the
>>>>>> fraction of a second. That way, there is no need to use
>>>>>> truncatedTo(SECONDS).
>>>>>>
>>>>>> StringBuilder appends can be used directly with formatters:
>>>>>>
>>>>>> sb.append(ZonedDateTime.ofInstant(time, zoneId).format(dtformatter));
>>>>>>
>>>>>> replace with
>>>>>>
>>>>>> dtformatter.formatTo(ZonedDateTime.ofInstant(time, zoneId), sb);
>>>>>
>>>>>
>>>>>
>>>>> Will look into this.
>>>>>
>>>>> Thanks again for your review! This is quite helpful.
>>>>>
>>>>> -- daniel
>>>>>
>>>>>
>>>>>>
>>>>>> thanks
>>>>>> Stephen
>>>>>>
>>>>>>
>>>>>>
>>>>>> On 13 Feb 2015 14:57, "Daniel Fuchs" <daniel.fuchs at oracle.com> wrote:
>>>>>>
>>>>>>> Hi,
>>>>>>>
>>>>>>> Please find below a patch for:
>>>>>>>
>>>>>>> 8072645: java.util.logging should use java.time to get more
>>>>>>>            precise time stamps
>>>>>>>
>>>>>>>
>>>>>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/webrev.00/
>>>>>>>
>>>>>>> specdiff:
>>>>>>> http://cr.openjdk.java.net/~dfuchs/webrev_8072645/
>>>>>>> specdiff-logging-time/java/util/logging/package-summary.html
>>>>>>>
>>>>>>> Overview:
>>>>>>> ---------
>>>>>>>
>>>>>>> The patch is made of the following pieces:
>>>>>>>
>>>>>>>    - LogRecord uses java.time.Clock's systemClock to get an
>>>>>>>      Instant in the best available resolution.
>>>>>>>
>>>>>>>      The instant is split into a number of milliseconds (a long)
>>>>>>>      and a nanosecond adjustment (an int).
>>>>>>>      The number of milliseconds is the same than what would have
>>>>>>>      been obtained by calling System.currentTimeMillis().
>>>>>>>
>>>>>>>    - LogRecord acquires a new serializable int nanoAdjustement field,
>>>>>>>      which can be used together with the number of milliseconds
>>>>>>>      to reconstruct the instant.
>>>>>>>
>>>>>>>    - SimpleFormatter is updated to pass a ZoneDateTime
>>>>>>>      instance to String.format, instead of a Date.
>>>>>>>
>>>>>>>      The effect of that is that the format string can now
>>>>>>>      be configure to print the full instant precision, if
>>>>>>>      needed.
>>>>>>>
>>>>>>>    - XMLformatter will add a new <nanos> element after the
>>>>>>>      <millis> element - if the value of the nanoAdjustment
>>>>>>>      field is not 0.
>>>>>>>
>>>>>>>      The <date> string will also contain the nano second
>>>>>>>      adjustment as well as the zone offset as formatted by
>>>>>>>      DateTimeFormatter.ISO_OFFSET_DATE_TIME
>>>>>>>
>>>>>>> Compatibility considerations:
>>>>>>> -----------------------------
>>>>>>>
>>>>>>> - The serial for of log record is backward/forward compatible.
>>>>>>>     I added a test to verify that.
>>>>>>>
>>>>>>> - XMLFormatter has acquired a new configurable property
>>>>>>>     '<FQCN>.printNanos' which allows to revert to the old
>>>>>>>     XML format, should the new format cause issues in
>>>>>>>     existing applications.
>>>>>>>
>>>>>>> - The logger.dtd will need to be updated, to support the
>>>>>>>     new optional <nanos> element. And for this matter,
>>>>>>>     should we update the logger.dtd or rather define a
>>>>>>>     logger-v2.dtd?
>>>>>>>     See planned modification:
>>>>>>>
>>>>>>> <http://cr.openjdk.java.net/~dfuchs/webrev_8072645/logger-
>>>>>>> dtd/logger.dtd.frames.html>
>>>>>>>
>>>>>>> best regards,
>>>>>>>
>>>>>>> -- daniel
>>>>>>>
>>>>>
>>>>
>>>
>



More information about the core-libs-dev mailing list