# HG changeset patch # User dfuchs # Date 1424886067 -3600 # Node ID 7956b5dc0eace44a135b3f2ba68f158ad86c4e29 # Parent 9918719cfcc02420948cacd0af072313f24ee82e 8072645: java.util.logging should use java.time to get more precise time stamps Summary: j.u.logging uses j.t.Instant to store LogRecord time stamps. XMLFormatter format is updated to allow for a new optional element containing a nano second adjustment. SimpleFormatter passes a ZonedDateTime object to String.format. LogRecord getMillis/setMillis are deprecated, replaced by getInstant/setInstant. Reviewed-by: scolebourne, plevart, rriggs Contributed-by: daniel.fuchs@oracle.com, peter.levart@gmail.com diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/src/java.base/share/classes/sun/util/logging/LoggingSupport.java --- a/jdk/src/java.base/share/classes/sun/util/logging/LoggingSupport.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/src/java.base/share/classes/sun/util/logging/LoggingSupport.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2013, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2009, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -29,7 +29,7 @@ import java.lang.reflect.Field; import java.security.AccessController; import java.security.PrivilegedAction; -import java.util.Date; +import java.time.ZonedDateTime; /** * Internal API to support JRE implementation to detect if the java.util.logging @@ -145,6 +145,11 @@ return proxy.getLevelValue(level); } + // Since JDK 9, logging uses java.time to get more precise time stamps. + // It is possible to configure the simple format to print nano seconds (.%1$tN) + // by specifying: + // java.util.logging.SimpleFormatter.format=%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS.%1$tN %1$Tp %2$s%n%4$s: %5$s%6$s%n + // in the logging configuration private static final String DEFAULT_FORMAT = "%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS %1$Tp %2$s%n%4$s: %5$s%6$s%n"; @@ -171,7 +176,7 @@ if (format != null) { try { // validate the user-defined format string - String.format(format, new Date(), "", "", "", "", ""); + String.format(format, ZonedDateTime.now(), "", "", "", "", ""); } catch (IllegalArgumentException e) { // illegal syntax; fall back to the default format format = DEFAULT_FORMAT; diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/src/java.base/share/classes/sun/util/logging/PlatformLogger.java --- a/jdk/src/java.base/share/classes/sun/util/logging/PlatformLogger.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/src/java.base/share/classes/sun/util/logging/PlatformLogger.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2009, 2013, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2009, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -32,8 +32,11 @@ import java.io.StringWriter; import java.security.AccessController; import java.security.PrivilegedAction; +import java.time.Clock; +import java.time.Instant; +import java.time.ZoneId; +import java.time.ZonedDateTime; import java.util.Arrays; -import java.util.Date; import java.util.HashMap; import java.util.Map; import sun.misc.JavaLangAccess; @@ -514,11 +517,9 @@ private static final String formatString = LoggingSupport.getSimpleFormat(false); // don't check logging.properties - - // minimize memory allocation - private Date date = new Date(); + private final ZoneId zoneId = ZoneId.systemDefault(); private synchronized String format(Level level, String msg, Throwable thrown) { - date.setTime(System.currentTimeMillis()); + ZonedDateTime zdt = ZonedDateTime.now(zoneId); String throwable = ""; if (thrown != null) { StringWriter sw = new StringWriter(); @@ -530,7 +531,7 @@ } return String.format(formatString, - date, + zdt, getCallerInfo(), name, level.name(), diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/src/java.logging/share/classes/java/util/logging/LogRecord.java --- a/jdk/src/java.logging/share/classes/java/util/logging/LogRecord.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/src/java.logging/share/classes/java/util/logging/LogRecord.java Wed Feb 25 18:41:07 2015 +0100 @@ -24,10 +24,12 @@ */ package java.util.logging; +import java.time.Instant; import java.util.*; import java.util.concurrent.atomic.AtomicInteger; import java.util.concurrent.atomic.AtomicLong; import java.io.*; +import java.time.Clock; import sun.misc.JavaLangAccess; import sun.misc.SharedSecrets; @@ -88,55 +90,94 @@ private static final ThreadLocal threadIds = new ThreadLocal<>(); /** - * @serial Logging message level + * Logging message level */ private Level level; /** - * @serial Sequence number + * Sequence number */ private long sequenceNumber; /** - * @serial Class that issued logging call + * Class that issued logging call */ private String sourceClassName; /** - * @serial Method that issued logging call + * Method that issued logging call */ private String sourceMethodName; /** - * @serial Non-localized raw message text + * Non-localized raw message text */ private String message; /** - * @serial Thread ID for thread that issued logging call. + * Thread ID for thread that issued logging call. */ private int threadID; /** - * @serial Event time in milliseconds since 1970 - */ - private long millis; - - /** - * @serial The Throwable (if any) associated with log message + * The Throwable (if any) associated with log message */ private Throwable thrown; /** - * @serial Name of the source Logger. + * Name of the source Logger. */ private String loggerName; /** - * @serial Resource bundle name to localized log message. + * Resource bundle name to localized log message. */ private String resourceBundleName; + /** + * Event time. + * @since 1.9 + */ + private Instant instant; + + /** + * @serialField level Level Logging message level + * @serialField sequenceNumber long Sequence number + * @serialField sourceClassName String Class that issued logging call + * @serialField sourceMethodName String Method that issued logging call + * @serialField message String Non-localized raw message text + * @serialField threadID int Thread ID for thread that issued logging call + * @serialField millis long Truncated event time in milliseconds since 1970 + * - calculated as getInstant().toEpochMilli(). + * The event time instant can be reconstructed using + * Instant.ofEpochSecond(millis/1000, (millis % 1000) * 1000_000 + nanoAdjustment) + * @serialField nanoAdjustment int Nanoseconds adjustment to the millisecond of + * event time - calculated as getInstant().getNano() % 1000_000 + * The event time instant can be reconstructed using + * Instant.ofEpochSecond(millis/1000, (millis % 1000) * 1000_000 + nanoAdjustment) + *

+ * Since: 1.9 + * @serialField thrown Throwable The Throwable (if any) associated with log + * message + * @serialField loggerName String Name of the source Logger + * @serialField resourceBundleName String Resource bundle name to localized + * log message + */ + private static final ObjectStreamField[] serialPersistentFields = + new ObjectStreamField[] { + new ObjectStreamField("level", Level.class), + new ObjectStreamField("sequenceNumber", long.class), + new ObjectStreamField("sourceClassName", String.class), + new ObjectStreamField("sourceMethodName", String.class), + new ObjectStreamField("message", String.class), + new ObjectStreamField("threadID", int.class), + new ObjectStreamField("millis", long.class), + new ObjectStreamField("nanoAdjustment", int.class), + new ObjectStreamField("thrown", Throwable.class), + new ObjectStreamField("loggerName", String.class), + new ObjectStreamField("resourceBundleName", String.class), + }; + private transient boolean needToInferCaller; private transient Object parameters[]; private transient ResourceBundle resourceBundle; @@ -164,7 +205,10 @@ * The sequence property will be initialized with a new unique value. * These sequence values are allocated in increasing order within a VM. *

- * The millis property will be initialized to the current time. + * Since JDK 1.9, the event time is represented by an {@link Instant}. + * The instant property will be initialized to the {@linkplain + * Instant#now() current instant}, using the best available + * {@linkplain Clock#systemUTC() clock} on the system. *

* The thread ID property will be initialized with a unique ID for * the current thread. @@ -173,6 +217,7 @@ * * @param level a logging level value * @param msg the raw non-localized logging message (may be null) + * @see java.time.Clock#systemUTC() */ public LogRecord(Level level, String msg) { this.level = Objects.requireNonNull(level); @@ -180,7 +225,7 @@ // Assign a thread ID and a unique sequence number. sequenceNumber = globalSequenceNumber.getAndIncrement(); threadID = defaultThreadID(); - millis = System.currentTimeMillis(); + instant = Instant.now(); needToInferCaller = true; } @@ -416,21 +461,63 @@ } /** - * Get event time in milliseconds since 1970. + * Get truncated event time in milliseconds since 1970. + * + * @return truncated event time in millis since 1970 + * + * @implSpec This is equivalent to calling + * {@link #getInstant() getInstant().toEpochMilli()}. * - * @return event time in millis since 1970 + * @deprecated To get the full nanosecond resolution event time, + * use {@link #getInstant()}. + * + * @see #getInstant() */ + @Deprecated public long getMillis() { - return millis; + return instant.toEpochMilli(); } /** * Set event time. * - * @param millis event time in millis since 1970 + * @param millis event time in millis since 1970. + * + * @implSpec This is equivalent to calling + * {@link #setInstant(java.time.Instant) + * setInstant(Instant.ofEpochMilli(millis))}. + * + * @deprecated To set event time with nanosecond resolution, + * use {@link #setInstant(java.time.Instant)}. + * + * @see #setInstant(java.time.Instant) */ + @Deprecated public void setMillis(long millis) { - this.millis = millis; + this.instant = Instant.ofEpochMilli(millis); + } + + /** + * Gets the instant that the event occurred. + * + * @return the instant that the event occurred. + * + * @since 1.9 + */ + public Instant getInstant() { + return instant; + } + + /** + * Sets the instant that the event occurred. + * + * @param instant the instant that the event occurred. + * + * @throws NullPointerException if {@code instant} is null. + * @since 1.9 + */ + public void setInstant(Instant instant) { + this.instant = Objects.requireNonNull(instant); } /** @@ -457,7 +544,7 @@ private static final long serialVersionUID = 5372048053134512534L; /** - * @serialData Default fields, followed by a two byte version number + * @serialData Serialized fields, followed by a two byte version number * (major byte, followed by minor byte), followed by information on * the log record parameter array. If there is no parameter array, * then -1 is written. If there is a parameter array (possible of zero @@ -467,8 +554,20 @@ * is written. */ private void writeObject(ObjectOutputStream out) throws IOException { - // We have to call defaultWriteObject first. - out.defaultWriteObject(); + // We have to write serialized fields first. + ObjectOutputStream.PutField pf = out.putFields(); + pf.put("level", level); + pf.put("sequenceNumber", sequenceNumber); + pf.put("sourceClassName", sourceClassName); + pf.put("sourceMethodName", sourceMethodName); + pf.put("message", message); + pf.put("threadID", threadID); + pf.put("millis", instant.toEpochMilli()); + pf.put("nanoAdjustment", instant.getNano() % 1000_000); + pf.put("thrown", thrown); + pf.put("loggerName", loggerName); + pf.put("resourceBundleName", resourceBundleName); + out.writeFields(); // Write our version number. out.writeByte(1); @@ -486,8 +585,21 @@ private void readObject(ObjectInputStream in) throws IOException, ClassNotFoundException { - // We have to call defaultReadObject first. - in.defaultReadObject(); + // We have to read serialized fields first. + ObjectInputStream.GetField gf = in.readFields(); + level = (Level) gf.get("level", null); + sequenceNumber = gf.get("sequenceNumber", 0L); + sourceClassName = (String) gf.get("sourceClassName", null); + sourceMethodName = (String) gf.get("sourceMethodName", null); + message = (String) gf.get("message", null); + threadID = gf.get("threadID", 0); + long millis = gf.get("millis", 0L); + int nanoOfMilli = gf.get("nanoAdjustment", 0); + instant = Instant.ofEpochSecond( + millis / 1000L, (millis % 1000L) * 1000_000L + nanoOfMilli); + thrown = (Throwable) gf.get("thrown", null); + loggerName = (String) gf.get("loggerName", null); + resourceBundleName = (String) gf.get("resourceBundleName", null); // Read version number. byte major = in.readByte(); diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/src/java.logging/share/classes/java/util/logging/SimpleFormatter.java --- a/jdk/src/java.logging/share/classes/java/util/logging/SimpleFormatter.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/src/java.logging/share/classes/java/util/logging/SimpleFormatter.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -27,8 +27,9 @@ package java.util.logging; import java.io.*; -import java.text.*; -import java.util.Date; +import java.time.LocalDateTime; +import java.time.ZoneId; +import java.time.ZonedDateTime; import sun.util.logging.LoggingSupport; /** @@ -59,8 +60,8 @@ public class SimpleFormatter extends Formatter { // format string for printing the log record - private static final String format = LoggingSupport.getSimpleFormat(); - private final Date dat = new Date(); + private final String format = LoggingSupport.getSimpleFormat(); + private final ZoneId zoneId = ZoneId.systemDefault(); /** * Format the given LogRecord. @@ -79,8 +80,9 @@ * java.util.Formatter} format string specified in the * {@code java.util.logging.SimpleFormatter.format} property * or the default format. - *

  • {@code date} - a {@link Date} object representing - * {@linkplain LogRecord#getMillis event time} of the log record.
  • + *
  • {@code date} - a {@link ZonedDateTime} object representing + * {@linkplain LogRecord#getInstant() event time} of the log record + * in the {@link ZoneId#systemDefault()} system time zone.
  • *
  • {@code source} - a string representing the caller, if available; * otherwise, the logger's name.
  • *
  • {@code logger} - the logger's name.
  • @@ -129,6 +131,16 @@ * Mar 22, 2011 1:11:31 PM MyClass fatal * SEVERE: several message with an exception * + *
  • {@code java.util.logging.SimpleFormatter.format="%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS.%1$tN %1$Tp %2$s%n%4$s: %5$s%6$s%n"} + *

    Since JDK 1.9, {@code java.util.logging} uses {@link + * java.time.Clock#systemUTC() java.time} to create more precise time + * stamps. + * The format above can be used to add a {@code .%1$tN} to the + * date/time formatting so that nanoseconds will also be printed: + *

    +     *     Feb 06, 2015 5:33:10.279216000 PM example.Main main
    +     *     INFO: This is a test
    +     *     
  • * *

    This method can also be overridden in a subclass. * It is recommended to use the {@link Formatter#formatMessage} @@ -137,8 +149,10 @@ * @param record the log record to be formatted. * @return a formatted log record */ + @Override public synchronized String format(LogRecord record) { - dat.setTime(record.getMillis()); + ZonedDateTime zdt = ZonedDateTime.ofInstant( + record.getInstant(), zoneId); String source; if (record.getSourceClassName() != null) { source = record.getSourceClassName(); @@ -159,7 +173,7 @@ throwable = sw.toString(); } return String.format(format, - dat, + zdt, source, record.getLoggerName(), record.getLevel().getLocalizedLevelName(), diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/src/java.logging/share/classes/java/util/logging/XMLFormatter.java --- a/jdk/src/java.logging/share/classes/java/util/logging/XMLFormatter.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/src/java.logging/share/classes/java/util/logging/XMLFormatter.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -26,8 +26,9 @@ package java.util.logging; -import java.io.*; import java.nio.charset.Charset; +import java.time.Instant; +import java.time.format.DateTimeFormatter; import java.util.*; /** @@ -40,11 +41,70 @@ * but it is recommended that it normally be used with UTF-8. The * character encoding can be set on the output Handler. * + * @implSpec Since JDK 1.9, instances of {@linkplain LogRecord} contain + * an {@link LogRecord#getInstant() Instant} which can have nanoseconds below + * the millisecond resolution. + * The DTD specification has been updated to allow for an optional + * {@code } element. By default, the XMLFormatter will compute the + * nanosecond adjustment below the millisecond resolution (using + * {@code LogRecord.getInstant().getNano() % 1000_000}) - and if this is not 0, + * this adjustment value will be printed in the new {@code } element. + * The event instant can then be reconstructed using + * {@code Instant.ofEpochSecond(millis/1000L, (millis % 1000L) * 1000_000L + nanos)} + * where {@code millis} and {@code nanos} represent the numbers serialized in + * the {@code } and {@code } elements, respectively. + *
    + * The {@code } element will now contain the whole instant as formatted + * by the {@link DateTimeFormatter#ISO_INSTANT DateTimeFormatter.ISO_INSTANT} + * formatter. + *

    + * For compatibility with old parsers, XMLFormatters can + * be configured to revert to the old format by specifying a + * {@code .useInstant = false} + * {@linkplain LogManager#getProperty(java.lang.String) property} in the + * logging configuration. When {@code useInstant} is {@code false}, the old + * formatting will be preserved. When {@code useInstant} is {@code true} + * (the default), the {@code } element will be printed and the + * {@code } element will contain the {@linkplain + * DateTimeFormatter#ISO_INSTANT formatted} instant. + *

    + * For instance, in order to configure plain instances of XMLFormatter to omit + * the new {@code } element, + * {@code java.util.logging.XMLFormatter.useInstant = false} can be specified + * in the logging configuration. + * * @since 1.4 */ public class XMLFormatter extends Formatter { - private LogManager manager = LogManager.getLogManager(); + private final LogManager manager = LogManager.getLogManager(); + private final boolean useInstant; + + /** + * Creates a new instance of XMLFormatter. + * + * @implSpec + * Since JDK 1.9, the XMLFormatter will print out the record {@linkplain + * LogRecord#getInstant() event time} as an Instant. This instant + * has the best resolution available on the system. The {@code } + * element will contain the instant as formatted by the {@link + * DateTimeFormatter#ISO_INSTANT}. + * In addition, an optional {@code } element containing a + * nanosecond adjustment will be printed if the instant contains some + * nanoseconds below the millisecond resolution. + *

    + * This new behavior can be turned off, and the old formatting restored, + * by specifying a property in the {@linkplain + * LogManager#getProperty(java.lang.String) logging configuration}. + * If {@code LogManager.getLogManager().getProperty( + * this.getClass().getName()+".useInstant")} is {@code "false"} or + * {@code "0"}, the old formatting will be restored. + */ + public XMLFormatter() { + useInstant = (manager == null) + || manager.getBooleanProperty( + this.getClass().getName()+".useInstant", true); + } // Append a two digit number. private void a2(StringBuilder sb, int x) { @@ -102,18 +162,35 @@ * @param record the log record to be formatted. * @return a formatted log record */ + @Override public String format(LogRecord record) { StringBuilder sb = new StringBuilder(500); sb.append("\n"); + final Instant instant = record.getInstant(); + sb.append(" "); - appendISO8601(sb, record.getMillis()); + if (useInstant) { + // If useInstant is true - we will print the instant in the + // date field, using the ISO_INSTANT formatter. + DateTimeFormatter.ISO_INSTANT.formatTo(instant, sb); + } else { + // If useInstant is false - we will keep the 'old' formating + appendISO8601(sb, instant.toEpochMilli()); + } sb.append("\n"); sb.append(" "); - sb.append(record.getMillis()); + sb.append(instant.toEpochMilli()); sb.append("\n"); + final int nanoAdjustment = instant.getNano() % 1000_000; + if (useInstant && nanoAdjustment != 0) { + sb.append(" "); + sb.append(nanoAdjustment); + sb.append("\n"); + } + sb.append(" "); sb.append(record.getSequenceNumber()); sb.append("\n"); @@ -223,6 +300,7 @@ * @param h The target handler (can be null) * @return a valid XML string */ + @Override public String getHead(Handler h) { StringBuilder sb = new StringBuilder(); String encoding; @@ -251,6 +329,7 @@ sb.append(encoding); sb.append("\""); sb.append(" standalone=\"no\"?>\n"); + sb.append("\n"); sb.append("\n"); return sb.toString(); @@ -262,6 +341,7 @@ * @param h The target handler (can be null) * @return a valid XML string */ + @Override public String getTail(Handler h) { return "\n"; } diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/lang/invoke/lambda/LogGeneratedClassesTest.java --- a/jdk/test/java/lang/invoke/lambda/LogGeneratedClassesTest.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/test/java/lang/invoke/lambda/LogGeneratedClassesTest.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2013, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -32,6 +32,7 @@ import java.io.IOException; import java.util.ArrayList; import java.util.List; +import java.util.function.Predicate; import java.nio.file.Files; import java.nio.file.Path; import java.nio.file.Paths; @@ -235,8 +236,23 @@ .filter(s -> s.startsWith("WARNING: Exception")) .count(), 2, "show error each capture"); - // dumpLong/com/example/nosense/nosense - assertEquals(Files.walk(Paths.get("dumpLong")).count(), 5, "Two lambda captured failed to log"); + // dumpLong/com/example/nonsense/nonsense + Path dumpPath = Paths.get("dumpLong/com/example/nonsense"); + Predicate filter = p -> p.getParent() == null || dumpPath.startsWith(p) || p.startsWith(dumpPath); + boolean debug = true; + if (debug) { + Files.walk(Paths.get("dumpLong")) + .forEachOrdered(p -> { + if (filter.test(p)) { + System.out.println("accepted: " + p.toString()); + } else { + System.out.println("filetered out: " + p.toString()); + } + }); + } + assertEquals(Files.walk(Paths.get("dumpLong")) + .filter(filter) + .count(), 5, "Two lambda captured failed to log"); tr.assertZero("Should still return 0"); } } diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/FileHandlerLongLimit.java --- a/jdk/test/java/util/logging/FileHandlerLongLimit.java Wed Feb 25 17:24:13 2015 +0000 +++ b/jdk/test/java/util/logging/FileHandlerLongLimit.java Wed Feb 25 18:41:07 2015 +0100 @@ -1,5 +1,5 @@ /* - * Copyright (c) 2014, Oracle and/or its affiliates. All rights reserved. + * Copyright (c) 2014, 2015, Oracle and/or its affiliates. All rights reserved. * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. * * This code is free software; you can redistribute it and/or modify it @@ -346,26 +346,29 @@ assertEquals(0, getWritten(metered), "written"); // now we're going to publish a series of log records + // we're using the same log record over and over to make + // sure we get the same amount of bytes. String msg = "this is at least 10 chars long"; - fh.publish(new LogRecord(Level.SEVERE, msg)); + LogRecord record = new LogRecord(Level.SEVERE, msg); + fh.publish(record); fh.flush(); long w = getWritten(metered); long offset = getWritten(metered); System.out.println("first offset is: " + offset); - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); offset = getWritten(metered) - w; w = getWritten(metered); System.out.println("second offset is: " + offset); - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); offset = getWritten(metered) - w; w = getWritten(metered); System.out.println("third offset is: " + offset); - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); offset = getWritten(metered) - w; System.out.println("fourth offset is: " + offset); @@ -377,7 +380,7 @@ // publish one more log record. we should still be just beneath // the limit - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); assertEquals(w+offset, getWritten(metered), "written"); @@ -392,9 +395,9 @@ // writing the first log record or just before writing the next // one. We publich two - so we're sure that the log must have // rotated. - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); - fh.publish(new LogRecord(Level.SEVERE, msg)); + fh.publish(record); fh.flush(); // Check that fh.meter is a different instance of MeteredStream. diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/HigherResolutionTimeStamps/LogRecordWithNanos.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/jdk/test/java/util/logging/HigherResolutionTimeStamps/LogRecordWithNanos.java Wed Feb 25 18:41:07 2015 +0100 @@ -0,0 +1,143 @@ +/* + * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ +import java.io.ByteArrayInputStream; +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.ObjectInputStream; +import java.io.ObjectOutputStream; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.SimpleFormatter; + +/** + * @test + * @bug 8072645 + * @summary tests that LogRecord has nanos... + * @run main LogRecordWithNanos + * @author danielfuchs + */ +public class LogRecordWithNanos { + + static final int MILLIS_IN_SECOND = 1000; + static final int NANOS_IN_MILLI = 1000_000; + static final int NANOS_IN_SECOND = 1000_000_000; + + static final boolean verbose = false; + + static final class TestAssertException extends RuntimeException { + TestAssertException(String msg) { super(msg); } + } + + private static void assertEquals(long expected, long received, String msg) { + if (expected != received) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + /** + * Serializes a log record, then deserializes it and check that both + * records match. + * @param record the log record to serialize & deserialize. + * @throws IOException Unexpected. + * @throws ClassNotFoundException Unexpected. + */ + public static void test(LogRecord record) + throws IOException, ClassNotFoundException { + + // Format the given logRecord using the SimpleFormatter + SimpleFormatter formatter = new SimpleFormatter(); + String str = formatter.format(record); + + // Serialize the given LogRecord + final ByteArrayOutputStream baos = new ByteArrayOutputStream(); + final ObjectOutputStream oos = new ObjectOutputStream(baos); + oos.writeObject(record); + oos.flush(); + oos.close(); + + // First checks that the log record can be deserialized + final ByteArrayInputStream bais = new ByteArrayInputStream(baos.toByteArray()); + final ObjectInputStream ois = new ObjectInputStream(bais); + final LogRecord record2 = (LogRecord)ois.readObject(); + + assertEquals(record.getMillis(), record2.getMillis(), "getMillis()"); + 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()"); + assertEquals(record.getMillis(), + record.getInstant().toEpochMilli(), + "getMillis()/getInstant().toEpochMilli()"); + assertEquals(record2.getMillis(), + record2.getInstant().toEpochMilli(), + "getMillis()/getInstant().toEpochMilli()"); + assertEquals((record.getMillis()%MILLIS_IN_SECOND)*NANOS_IN_MILLI + + (record.getInstant().getNano() % NANOS_IN_MILLI), + record.getInstant().getNano(), + "record.getMillis()%1000)*1000_000" + + " + record.getInstant().getNano()%1000_000 / getInstant().getNano()"); + assertEquals((record2.getMillis()%MILLIS_IN_SECOND)*NANOS_IN_MILLI + + (record2.getInstant().getNano() % NANOS_IN_MILLI), + record2.getInstant().getNano(), + "record2.getMillis()%1000)*1000_000" + + " + record2.getInstant().getNano()%1000_000 / getInstant().getNano()"); + + // Format the deserialized LogRecord using the SimpleFormatter, and + // check that the string representation obtained matches the string + // representation of the original LogRecord + String str2 = formatter.format(record2); + if (!str.equals(str2)) + throw new RuntimeException("Unexpected values in deserialized object:" + + "\n\tExpected: " + str + + "\n\tRetrieved: "+str); + + } + + + public static void main(String[] args) throws Exception { + int count=0; + for (int i=0; i<1000; i++) { + LogRecord record = new LogRecord(Level.INFO, "Java Version: {0}"); + record.setLoggerName("test"); + record.setParameters(new Object[] {System.getProperty("java.version")}); + if (record.getInstant().getNano() % 1000_000 != 0) { + count++; + } + test(record); + } + if (count == 0) { + throw new RuntimeException("Expected at least one record to have nanos"); + } + System.out.println(count + "/1000 records had nano adjustment."); + } + +} diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/HigherResolutionTimeStamps/LogRecordWithNanosAPI.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/jdk/test/java/util/logging/HigherResolutionTimeStamps/LogRecordWithNanosAPI.java Wed Feb 25 18:41:07 2015 +0100 @@ -0,0 +1,308 @@ +/* + * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ +import java.io.ByteArrayInputStream; +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.ObjectInputStream; +import java.io.ObjectOutputStream; +import java.time.Instant; +import java.util.Objects; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.SimpleFormatter; + +/** + * @test + * @bug 8072645 + * @summary tests the new methods added to LogRecord. + * @run main LogRecordWithNanosAPI + * @author danielfuchs + */ +public class LogRecordWithNanosAPI { + + static final int MILLIS_IN_SECOND = 1000; + static final int NANOS_IN_MILLI = 1000_000; + static final int NANOS_IN_SECOND = 1000_000_000; + + static final boolean verbose = true; + + static final class TestAssertException extends RuntimeException { + TestAssertException(String msg) { super(msg); } + } + + private static void assertEquals(long expected, long received, String msg) { + if (expected != received) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + private static void assertEquals(Object expected, Object received, String msg) { + if (!Objects.equals(expected, received)) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + // The nano second fractional part of a second, contained in a time expressed + // as a number of millisecond from the epoch. + private static long nanoInSecondFromEpochMilli(long millis) { + return (((millis%MILLIS_IN_SECOND) + MILLIS_IN_SECOND)%MILLIS_IN_SECOND)*NANOS_IN_MILLI; + } + + /** + * Serializes a log record, then deserializes it and check that both + * records match. + * @param record the log record to serialize & deserialize. + * @param hasExceedingNanos whether the record has a nano adjustment whose + * value exceeds 1ms. + * @throws IOException Unexpected. + * @throws ClassNotFoundException Unexpected. + */ + public static void test(LogRecord record, boolean hasExceedingNanos) + throws IOException, ClassNotFoundException { + + // Format the given logRecord using the SimpleFormatter + SimpleFormatter formatter = new SimpleFormatter(); + String str = formatter.format(record); + + // Serialize the given LogRecord + final ByteArrayOutputStream baos = new ByteArrayOutputStream(); + final ObjectOutputStream oos = new ObjectOutputStream(baos); + oos.writeObject(record); + oos.flush(); + oos.close(); + + // First checks that the log record can be deserialized + final ByteArrayInputStream bais = + new ByteArrayInputStream(baos.toByteArray()); + final ObjectInputStream ois = new ObjectInputStream(bais); + final LogRecord record2 = (LogRecord)ois.readObject(); + + assertEquals(record.getMillis(), record2.getMillis(), "getMillis()"); + 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()"); + long millis = record.getMillis(); + millis = hasExceedingNanos + ? Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + + record.getInstant().getNano() % NANOS_IN_MILLI).toEpochMilli() + : millis; + assertEquals(millis, record.getInstant().toEpochMilli(), + "getMillis()/getInstant().toEpochMilli()"); + millis = record2.getMillis(); + millis = hasExceedingNanos + ? Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + + record2.getInstant().getNano() % NANOS_IN_MILLI).toEpochMilli() + : millis; + assertEquals(millis, record2.getInstant().toEpochMilli(), + "getMillis()/getInstant().toEpochMilli()"); + long nanos = nanoInSecondFromEpochMilli(record.getMillis()) + + record.getInstant().getNano() % NANOS_IN_MILLI; + assertEquals(nanos, record.getInstant().getNano(), + "nanoInSecondFromEpochMilli(record.getMillis())" + + " + record.getInstant().getNano() % NANOS_IN_MILLI /getInstant().getNano()"); + nanos = nanoInSecondFromEpochMilli(record2.getMillis()) + + record2.getInstant().getNano() % NANOS_IN_MILLI; + assertEquals(nanos, record2.getInstant().getNano(), + "nanoInSecondFromEpochMilli(record2.getMillis())" + + " + record2.getInstant().getNano() % NANOS_IN_MILLI /getInstant().getNano()"); + + // Format the deserialized LogRecord using the SimpleFormatter, and + // check that the string representation obtained matches the string + // representation of the original LogRecord + String str2 = formatter.format(record2); + if (!str.equals(str2)) + throw new RuntimeException("Unexpected values in deserialized object:" + + "\n\tExpected: " + str + + "\n\tRetrieved: "+str); + + } + + + public static void main(String[] args) throws Exception { + int count=0; + LogRecord record = new LogRecord(Level.INFO, "Java Version: {0}"); + record.setLoggerName("test"); + record.setParameters(new Object[] {System.getProperty("java.version")}); + final int nanos = record.getInstant().getNano() % NANOS_IN_MILLI; + final long millis = record.getMillis(); + final Instant instant = record.getInstant(); + if (millis != instant.toEpochMilli()) { + throw new RuntimeException("Unexpected millis: " + + record.getMillis()); + } + test(record, false); + + // nano adjustment < 1ms (canonical case) + int newNanos = (nanos + 111111) % NANOS_IN_MILLI; + record.setInstant(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + newNanos)); + assertEquals(newNanos, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis, record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newNanos), + record.getInstant(), "record.getInstant()"); + test(record, false); + assertEquals(newNanos, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis, record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newNanos), + record.getInstant(), "record.getInstant()"); + + // nano adjustment > 1ms - non canonical - should still work + int newExceedingNanos = 2111_111; + record.setInstant(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + newExceedingNanos)); + assertEquals(newExceedingNanos % NANOS_IN_MILLI, + record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis + newExceedingNanos / NANOS_IN_MILLI, + record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + test(record, true); + assertEquals(newExceedingNanos % NANOS_IN_MILLI, + record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis + newExceedingNanos / NANOS_IN_MILLI, + record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + + // nano adjustement > 1s - non canonical - should still work + newExceedingNanos = 1111_111_111; + record.setInstant(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + newExceedingNanos)); + assertEquals(newExceedingNanos % NANOS_IN_MILLI, + record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis + newExceedingNanos / NANOS_IN_MILLI, + record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + test(record, true); + assertEquals(newExceedingNanos % NANOS_IN_MILLI, + record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis + newExceedingNanos / NANOS_IN_MILLI, + record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + + // nano adjustement < 0 - non canonical - should still work + newExceedingNanos = -1; + record.setInstant(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + newExceedingNanos)); + assertEquals(newExceedingNanos + NANOS_IN_MILLI, + record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + assertEquals(millis -1, record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + test(record, true); + record.setInstant(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + newExceedingNanos)); + assertEquals(millis -1, record.getMillis(), "record.getMillis()"); + assertEquals(Instant.ofEpochSecond(millis/MILLIS_IN_SECOND, + (millis%MILLIS_IN_SECOND)*NANOS_IN_MILLI + newExceedingNanos), + record.getInstant(), "record.getInstant()"); + + // setMillis + record.setMillis(millis-1); + assertEquals(millis-1, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(millis-1, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + test(record, false); + assertEquals(millis-1, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(millis-1, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + + // setMillis to 0 + record.setMillis(0); + assertEquals(0, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(0, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + test(record, false); + assertEquals(0, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(0, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + + // setMillis to -1 + record.setMillis(-1); + assertEquals(-1, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(-1, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + test(record, false); + assertEquals(-1, record.getInstant().toEpochMilli(), + "record.getInstant().toEpochMilli()"); + assertEquals(-1, record.getMillis(), + "record.getMillis()"); + assertEquals(0, record.getInstant().getNano() % NANOS_IN_MILLI, + "record.getInstant().getNano() % NANOS_IN_MILLI"); + + try { + record.setInstant(null); + } catch (NullPointerException x) { + System.out.println("Got expected NPE when trying to call record.setInstant(null): " + x); + } + + } + +} diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/HigherResolutionTimeStamps/SerializeLogRecord.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/jdk/test/java/util/logging/HigherResolutionTimeStamps/SerializeLogRecord.java Wed Feb 25 18:41:07 2015 +0100 @@ -0,0 +1,363 @@ +/* + * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ +import java.io.ByteArrayInputStream; +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.io.ObjectInputStream; +import java.io.ObjectOutputStream; +import java.time.ZoneId; +import java.util.Base64; +import java.util.Locale; +import java.util.TimeZone; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.SimpleFormatter; +import java.util.regex.Matcher; +import java.util.regex.Pattern; +import java.util.stream.Stream; + +/** + * @test + * @bug 8072645 + * @summary tests the compatibility of LogRecord serial form between + * JDK 8 and JDK 9. Ideally this test should be run on both platforms. + * (It is designed to run on both). + * @run main/othervm SerializeLogRecord + * @author danielfuchs + */ +public class SerializeLogRecord { + + /** + * Serializes a log record, encode the serialized bytes in base 64, and + * prints pseudo java code that can be cut and pasted into this test. + * @param record the log record to serialize, encode in base 64, and for + * which test data will be generated. + * @return A string containing the generated pseudo java code. + * @throws IOException Unexpected. + * @throws ClassNotFoundException Unexpected. + */ + public static String generate(LogRecord record) throws IOException, ClassNotFoundException { + + // Format the given logRecord using the SimpleFormatter + SimpleFormatter formatter = new SimpleFormatter(); + String str = formatter.format(record); + + // Serialize the given LogRecord + final ByteArrayOutputStream baos = new ByteArrayOutputStream(); + final ObjectOutputStream oos = new ObjectOutputStream(baos); + oos.writeObject(record); + oos.flush(); + oos.close(); + + // Now we're going to perform a number of smoke tests before + // generating the Java pseudo code. + // + // First checks that the log record can be deserialized + final ByteArrayInputStream bais = new ByteArrayInputStream(baos.toByteArray()); + final ObjectInputStream ois = new ObjectInputStream(bais); + final LogRecord record2 = (LogRecord)ois.readObject(); + + // Format the deserialized LogRecord using the SimpleFormatter, and + // check that the string representation obtained matches the string + // representation of the original LogRecord + String str2 = formatter.format(record2); + if (!str.equals(str2)) throw new RuntimeException("Unexpected values in deserialized object:" + + "\n\tExpected: " + str + + "\n\tRetrieved: "+str); + + // Now get a Base64 string representation of the serialized bytes. + final String base64 = Base64.getEncoder().encodeToString(baos.toByteArray()); + + // Check that we can deserialize a log record from the Base64 string + // representation we just computed. + final ByteArrayInputStream bais2 = new ByteArrayInputStream(Base64.getDecoder().decode(base64)); + final ObjectInputStream ois2 = new ObjectInputStream(bais2); + final LogRecord record3 = (LogRecord)ois2.readObject(); + + // Format the new deserialized LogRecord using the SimpleFormatter, and + // check that the string representation obtained matches the string + // representation of the original LogRecord + String str3 = formatter.format(record3); + if (!str.equals(str3)) throw new RuntimeException("Unexpected values in deserialized object:" + + "\n\tExpected: " + str + + "\n\tRetrieved: "+str); + //System.out.println(base64); + //System.out.println(); + + // Generates the Java Pseudo code that can be cut & pasted into + // this test (see Jdk8SerializedLog and Jdk9SerializedLog below) + final StringBuilder sb = new StringBuilder(); + sb.append(" /**").append('\n'); + sb.append(" * Base64 encoded string for LogRecord object.").append('\n'); + sb.append(" * Java version: ").append(System.getProperty("java.version")).append('\n'); + sb.append(" **/").append('\n'); + sb.append(" final String base64 = ").append("\n "); + final int last = base64.length() - 1; + for (int i=0; i TestCase.valueOf(x)).forEach((x) -> { + switch(x) { + case GENERATE: generate(); break; + case TESTJDK8: Jdk8SerializedLog.test(); break; + case TESTJDK9: Jdk9SerializedLog.test(); break; + } + }); + } +} diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/HigherResolutionTimeStamps/SimpleFormatterNanos.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/jdk/test/java/util/logging/HigherResolutionTimeStamps/SimpleFormatterNanos.java Wed Feb 25 18:41:07 2015 +0100 @@ -0,0 +1,155 @@ +/* + * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ +import java.time.Instant; +import java.time.ZoneId; +import java.time.ZonedDateTime; +import java.util.Locale; +import java.util.logging.Level; +import java.util.logging.LogRecord; +import java.util.logging.SimpleFormatter; + +/** + * @test + * @bug 8072645 + * @summary tests that SimpleFormatter can print out dates with the new + * nanosecond precision. + * @run main/othervm SimpleFormatterNanos + * @author danielfuchs + */ +public class SimpleFormatterNanos { + + static final int MILLIS_IN_SECOND = 1000; + static final int NANOS_IN_MILLI = 1000_000; + static final int NANOS_IN_MICRO = 1000; + static final int NANOS_IN_SECOND = 1000_000_000; + + static final boolean verbose = true; + + static final class TestAssertException extends RuntimeException { + TestAssertException(String msg) { super(msg); } + } + + private static void assertEquals(long expected, long received, String msg) { + if (expected != received) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + static int getNanoAdjustment(LogRecord record) { + return record.getInstant().getNano() % NANOS_IN_MILLI; + } + static void setNanoAdjustment(LogRecord record, int nanos) { + record.setInstant(Instant.ofEpochSecond(record.getInstant().getEpochSecond(), + (record.getInstant().getNano() / NANOS_IN_MILLI) * NANOS_IN_MILLI + nanos)); + } + + public static void main(String[] args) throws Exception { + + Locale.setDefault(Locale.ENGLISH); + LogRecord record = new LogRecord(Level.INFO, "Java Version: {0}"); + record.setLoggerName("test"); + record.setParameters(new Object[] {System.getProperty("java.version")}); + int nanos = getNanoAdjustment(record); + long millis = record.getMillis(); + // make sure we don't have leading zeros when printing below + // the second precision + if (millis % MILLIS_IN_SECOND < 100) millis = millis + 100; + // make sure we have some nanos + if (nanos % NANOS_IN_MICRO == 0) nanos = nanos + 999; + record.setMillis(millis); + setNanoAdjustment(record, nanos); + final Instant instant = record.getInstant(); + if (nanos < 0) { + throw new RuntimeException("Unexpected negative nano adjustment: " + + getNanoAdjustment(record)); + } + if (nanos >= NANOS_IN_MILLI) { + throw new RuntimeException("Nano adjustment exceeds 1ms: " + + getNanoAdjustment(record)); + } + if (millis != record.getMillis()) { + throw new RuntimeException("Unexpected millis: " + millis + " != " + + record.getMillis()); + } + if (millis != record.getInstant().toEpochMilli()) { + throw new RuntimeException("Unexpected millis: " + + record.getInstant().toEpochMilli()); + } + ZonedDateTime zdt = ZonedDateTime.ofInstant(instant, ZoneId.systemDefault()); + int zdtNanos = zdt.getNano(); + long expectedNanos = (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + nanos; + assertEquals(expectedNanos, instant.getNano(), "Instant.getNano()"); + assertEquals(expectedNanos, zdtNanos, "ZonedDateTime.getNano()"); + String match = "."+expectedNanos+" "; + + System.out.println("Testing with default format..."); + + SimpleFormatter formatter = new SimpleFormatter(); + String str = formatter.format(record); + if (str.contains(match)) { + throw new RuntimeException("SimpleFormatter.format()" + + " string contains unexpected nanos: " + + "\n\tdid not expect match for: '" + match + "'" + + "\n\tin: " + str); + } + + System.out.println("Nanos omitted as expected: no '"+match+"' in "+str); + + + System.out.println("Changing format to print nanos..."); + System.setProperty("java.util.logging.SimpleFormatter.format", + "%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS.%1$tN %1$Tp %2$s%n%4$s: %5$s%6$s%n"); + + SimpleFormatter formatter2 = new SimpleFormatter(); + str = formatter2.format(record); + if (!str.contains(match)) { + throw new RuntimeException("SimpleFormatter.format()" + + " string does not contain expected nanos: " + + "\n\texpected match for: '" + match + "'" + + "\n\tin: " + str); + } + System.out.println("Found expected match for '"+match+"' in "+str); + + + System.out.println("Changing format to omit nanos..."); + System.setProperty("java.util.logging.SimpleFormatter.format", + "%1$tb %1$td, %1$tY %1$tl:%1$tM:%1$tS %1$Tp %2$s%n%4$s: %5$s%6$s%n"); + + SimpleFormatter formatter3 = new SimpleFormatter(); + str = formatter3.format(record); + String notMatch = match; + if (str.contains(notMatch)) { + throw new RuntimeException("SimpleFormatter.format()" + + " string contains unexpected nanos: " + + "\n\tdid not expect match for: '" + notMatch + "'" + + "\n\tin: " + str); + } + System.out.println("Nanos omitted as expected: no '"+notMatch+"' in "+str); + + } + +} diff -r 9918719cfcc0 -r 7956b5dc0eac jdk/test/java/util/logging/HigherResolutionTimeStamps/XmlFormatterNanos.java --- /dev/null Thu Jan 01 00:00:00 1970 +0000 +++ b/jdk/test/java/util/logging/HigherResolutionTimeStamps/XmlFormatterNanos.java Wed Feb 25 18:41:07 2015 +0100 @@ -0,0 +1,274 @@ +/* + * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved. + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER. + * + * This code is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License version 2 only, as + * published by the Free Software Foundation. + * + * This code is distributed in the hope that it will be useful, but WITHOUT + * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or + * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License + * version 2 for more details (a copy is included in the LICENSE file that + * accompanied this code). + * + * You should have received a copy of the GNU General Public License version + * 2 along with this work; if not, write to the Free Software Foundation, + * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA. + * + * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA + * or visit www.oracle.com if you need additional information or have any + * questions. + */ +import java.io.ByteArrayInputStream; +import java.io.ByteArrayOutputStream; +import java.io.IOException; +import java.time.Instant; +import java.time.ZoneId; +import java.time.ZonedDateTime; +import java.time.format.DateTimeFormatter; +import java.time.temporal.ChronoUnit; +import java.util.Arrays; +import java.util.Collections; +import java.util.List; +import java.util.Locale; +import java.util.Objects; +import java.util.Properties; +import java.util.logging.Level; +import java.util.logging.LogManager; +import java.util.logging.LogRecord; +import java.util.logging.XMLFormatter; + +/** + * @test + * @bug 8072645 + * @summary tests that XmlFormatter will print out dates with the new + * nanosecond precision. + * @run main/othervm XmlFormatterNanos + * @author danielfuchs + */ +public class XmlFormatterNanos { + + static final int MILLIS_IN_SECOND = 1000; + static final int NANOS_IN_MILLI = 1000_000; + static final int NANOS_IN_MICRO = 1000; + static final int NANOS_IN_SECOND = 1000_000_000; + + static final boolean verbose = true; + + static final class TestAssertException extends RuntimeException { + TestAssertException(String msg) { super(msg); } + } + + private static void assertEquals(long expected, long received, String msg) { + if (expected != received) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + private static void assertEquals(Object expected, Object received, String msg) { + if (!Objects.equals(expected, received)) { + throw new TestAssertException("Unexpected result for " + msg + + ".\n\texpected: " + expected + + "\n\tactual: " + received); + } else if (verbose) { + System.out.println("Got expected " + msg + ": " + received); + } + } + + static class CustomXMLFormatter extends XMLFormatter {} + + static class Configuration { + final Properties propertyFile; + private Configuration(Properties properties) { + propertyFile = properties; + } + public Configuration apply() { + try { + ByteArrayOutputStream bytes = new ByteArrayOutputStream(); + propertyFile.store(bytes, testName()); + ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray()); + LogManager.getLogManager().readConfiguration(bais); + } catch (IOException ex) { + throw new RuntimeException(ex); + } + return this; + } + + public static String useInstantProperty(Class type) { + return type.getName()+".useInstant"; + } + + public boolean useInstant(XMLFormatter formatter) { + return Boolean.parseBoolean(propertyFile.getProperty( + formatter.getClass().getName()+".useInstant", "true")); + } + + public String testName() { + return propertyFile.getProperty("test.name", "????"); + } + + public static Configuration of(Properties props) { + return new Configuration(props); + } + + public static Configuration apply(Properties props) { + return of(props).apply(); + } + } + + final static List properties; + static { + Properties props1 = new Properties(); + props1.setProperty("test.name", "with XML nano element (default)"); + Properties props2 = new Properties(); + props2.setProperty("test.name", "with XML nano element (standard=true, custom=false)"); + props2.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "true"); + props2.setProperty(Configuration.useInstantProperty(CustomXMLFormatter.class), "false"); + Properties props3 = new Properties(); + props3.setProperty("test.name", "with XML nano element (standard=false, custom=true)"); + props3.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "false"); + props3.setProperty(Configuration.useInstantProperty(CustomXMLFormatter.class), "true"); + + properties = Collections.unmodifiableList(Arrays.asList( + props1, + props2)); + } + + public static void main(String[] args) throws Exception { + Locale.setDefault(Locale.ENGLISH); + properties.stream().forEach(XmlFormatterNanos::test); + } + + static int getNanoAdjustment(LogRecord record) { + return record.getInstant().getNano() % NANOS_IN_MILLI; + } + static void setNanoAdjustment(LogRecord record, int nanos) { + record.setInstant(Instant.ofEpochSecond(record.getInstant().getEpochSecond(), + (record.getInstant().getNano() / NANOS_IN_MILLI) * NANOS_IN_MILLI + nanos)); + } + + public static void test(Properties props) { + Configuration conf = Configuration.apply(props); + + LogRecord record = new LogRecord(Level.INFO, "Test Name: {0}"); + record.setLoggerName("test"); + record.setParameters(new Object[] {conf.testName()}); + int nanos = record.getInstant().getNano() % NANOS_IN_MILLI; + long millis = record.getMillis(); + // make sure we don't have leading zeros when printing below + // the second precision + if (millis % MILLIS_IN_SECOND < 100) millis = millis + 100; + // make sure we some nanos - and make sure we don't have + // trailing zeros + if (nanos % 10 == 0) nanos = nanos + 7; + + record.setMillis(millis); + setNanoAdjustment(record, nanos); + final Instant instant = record.getInstant(); + if (nanos < 0) { + throw new RuntimeException("Unexpected negative nano adjustment: " + + getNanoAdjustment(record)); + } + if (nanos >= NANOS_IN_MILLI) { + throw new RuntimeException("Nano adjustment exceeds 1ms: " + + getNanoAdjustment(record)); + } + if (millis != record.getMillis()) { + throw new RuntimeException("Unexpected millis: " + millis + " != " + + record.getMillis()); + } + if (millis != record.getInstant().toEpochMilli()) { + throw new RuntimeException("Unexpected millis: " + + record.getInstant().toEpochMilli()); + } + long expectedNanos = (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + nanos; + assertEquals(expectedNanos, instant.getNano(), "Instant.getNano()"); + + XMLFormatter formatter = new XMLFormatter(); + testMatching(formatter, record, instant, expectedNanos, conf.useInstant(formatter)); + + XMLFormatter custom = new CustomXMLFormatter(); + testMatching(custom, record, instant, expectedNanos, conf.useInstant(custom)); + } + + private static void testMatching(XMLFormatter formatter, + LogRecord record, Instant instant, long expectedNanos, + boolean useInstant) { + + ZonedDateTime zdt = ZonedDateTime.ofInstant(instant, ZoneId.systemDefault()); + int zdtNanos = zdt.getNano(); + assertEquals(expectedNanos, zdtNanos, "ZonedDateTime.getNano()"); + + String str = formatter.format(record); + + String match = "."+expectedNanos; + if (str.contains(match) != useInstant) { + throw new RuntimeException(formatter.getClass().getSimpleName() + + ".format()" + + " string does not contain expected nanos: " + + "\n\texpected match for: '" + match + "'" + + "\n\tin: \n" + str); + } + System.out.println("Found expected match for '"+match+"' in \n"+str); + + match = ""+instant.toEpochMilli()+""; + if (!str.contains(match)) { + throw new RuntimeException(formatter.getClass().getSimpleName() + + ".format()" + + " string does not contain expected millis: " + + "\n\texpected match for: '" + match + "'" + + "\n\tin: \n" + str); + } + System.out.println("Found expected match for '"+match+"' in \n"+str); + + match = ""; + if (str.contains(match) != useInstant) { + throw new RuntimeException(formatter.getClass().getSimpleName() + + ".format()" + + " string " + + (useInstant + ? "does not contain expected nanos: " + : "contains unexpected nanos: ") + + "\n\t" + (useInstant ? "expected" : "unexpected") + + " match for: '" + match + "'" + + "\n\tin: \n" + str); + } + match = ""+getNanoAdjustment(record)+""; + if (str.contains(match) != useInstant) { + throw new RuntimeException(formatter.getClass().getSimpleName() + + ".format()" + + " string " + + (useInstant + ? "does not contain expected nanos: " + : "contains unexpected nanos: ") + + "\n\t" + (useInstant ? "expected" : "unexpected") + + " match for: '" + match + "'" + + "\n\tin: \n" + str); + } + if (useInstant) { + System.out.println("Found expected match for '"+match+"' in \n"+str); + } else { + System.out.println("As expected '"+match+"' is not present in \n"+str); + } + + match = useInstant ? DateTimeFormatter.ISO_INSTANT.format(instant) + : zdt.truncatedTo(ChronoUnit.SECONDS) + .format(DateTimeFormatter.ISO_LOCAL_DATE_TIME); + match = ""+match+""; + if (!str.contains(match)) { + throw new RuntimeException(formatter.getClass().getSimpleName() + + ".format()" + + " string does not contain expected date: " + + "\n\texpected match for: '" + match + "'" + + "\n\tin: \n" + str); + } + System.out.println("Found expected match for '"+match+"' in \n"+str); + + } + +}