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.fu...@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.fu...@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





Reply via email to