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

Wed Feb 18 15:13:32 UTC 2015

Daniel,

Was it determined if you were going to modify the existing logger.dtd or create a logger-v2.dtd?  If you are going to create a v2 then I think it might make sense to make dtd log manger property for the XMLFormatter instead of useInstant property.  So if you are using v2 then instant is enabled.  V3 would be instant enabled and foo enabled and so on.

Jason

----------------------------------------
> Date: Tue, 17 Feb 2015 20:33:15 +0100
> From: daniel.fuchs at oracle.com
> To: scolebourne at joda.org; core-libs-dev at openjdk.java.net; peter.levart at gmail.com
> Subject: Re: RFR: 8072645: java.util.logging should use java.time to get more precise time stamps
>
> 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
>>>>>
>>>
>>
> 		 	   		  