1 /*
2  * Copyright (c) 2015, Oracle and/or its affiliates. All rights reserved.
3  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4  *
5  * This code is free software; you can redistribute it and/or modify it
6  * under the terms of the GNU General Public License version 2 only, as
7  * published by the Free Software Foundation.
8  *
9  * This code is distributed in the hope that it will be useful, but WITHOUT
10  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11  * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
12  * version 2 for more details (a copy is included in the LICENSE file that
13  * accompanied this code).
14  *
15  * You should have received a copy of the GNU General Public License version
16  * 2 along with this work; if not, write to the Free Software Foundation,
17  * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18  *
19  * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
20  * or visit www.oracle.com if you need additional information or have any
21  * questions.
22  */
23 import java.io.ByteArrayInputStream;
24 import java.io.ByteArrayOutputStream;
25 import java.io.IOException;
26 import java.time.Instant;
27 import java.time.ZoneId;
28 import java.time.ZonedDateTime;
29 import java.time.format.DateTimeFormatter;
30 import java.time.temporal.ChronoUnit;
31 import java.util.Arrays;
32 import java.util.Collections;
33 import java.util.List;
34 import java.util.Locale;
35 import java.util.Objects;
36 import java.util.Properties;
37 import java.util.logging.Level;
38 import java.util.logging.LogManager;
39 import java.util.logging.LogRecord;
40 import java.util.logging.XMLFormatter;
41 
42 /**
43  * @test
44  * @bug 8072645
45  * @summary tests that XmlFormatter will print out dates with the new
46  *                nanosecond precision.
47  * @run main/othervm XmlFormatterNanos
48  * @author danielfuchs
49  */
50 public class XmlFormatterNanos {
51 
52     static final int MILLIS_IN_SECOND = 1000;
53     static final int NANOS_IN_MILLI = 1000_000;
54     static final int NANOS_IN_MICRO = 1000;
55     static final int NANOS_IN_SECOND = 1000_000_000;
56 
57     static final boolean verbose = true;
58 
59     static final class TestAssertException extends RuntimeException {
TestAssertException(String msg)60         TestAssertException(String msg) { super(msg); }
61     }
62 
assertEquals(long expected, long received, String msg)63     private static void assertEquals(long expected, long received, String msg) {
64         if (expected != received) {
65             throw new TestAssertException("Unexpected result for " + msg
66                     + ".\n\texpected: " + expected
67                     +  "\n\tactual:   " + received);
68         } else if (verbose) {
69             System.out.println("Got expected " + msg + ": " + received);
70         }
71     }
72 
assertEquals(Object expected, Object received, String msg)73     private static void assertEquals(Object expected, Object received, String msg) {
74         if (!Objects.equals(expected, received)) {
75             throw new TestAssertException("Unexpected result for " + msg
76                     + ".\n\texpected: " + expected
77                     +  "\n\tactual:   " + received);
78         } else if (verbose) {
79             System.out.println("Got expected " + msg + ": " + received);
80         }
81     }
82 
83     static class CustomXMLFormatter extends XMLFormatter {}
84 
85     static class Configuration {
86         final Properties propertyFile;
Configuration(Properties properties)87         private Configuration(Properties properties) {
88             propertyFile = properties;
89         }
apply()90         public Configuration apply() {
91             try {
92                 ByteArrayOutputStream bytes = new ByteArrayOutputStream();
93                 propertyFile.store(bytes, testName());
94                 ByteArrayInputStream bais = new ByteArrayInputStream(bytes.toByteArray());
95                 LogManager.getLogManager().readConfiguration(bais);
96             } catch (IOException ex) {
97                 throw new RuntimeException(ex);
98             }
99             return this;
100         }
101 
useInstantProperty(Class<?> type)102         public static String useInstantProperty(Class<?> type) {
103             return type.getName()+".useInstant";
104         }
105 
useInstant(XMLFormatter formatter)106         public boolean useInstant(XMLFormatter formatter) {
107             return Boolean.parseBoolean(propertyFile.getProperty(
108                     formatter.getClass().getName()+".useInstant", "true"));
109         }
110 
testName()111         public String testName() {
112             return propertyFile.getProperty("test.name", "????");
113         }
114 
of(Properties props)115         public static Configuration of(Properties props) {
116             return new Configuration(props);
117         }
118 
apply(Properties props)119         public static Configuration apply(Properties props) {
120             return of(props).apply();
121         }
122     }
123 
124     static final List<Properties> properties;
125     static {
126         Properties props1 = new Properties();
127         props1.setProperty("test.name", "with XML nano element (default)");
128         Properties props2 = new Properties();
129         props2.setProperty("test.name", "with XML nano element (standard=true, custom=false)");
Configuration.useInstantProperty(XMLFormatter.class)130         props2.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "true");
Configuration.useInstantProperty(CustomXMLFormatter.class)131         props2.setProperty(Configuration.useInstantProperty(CustomXMLFormatter.class), "false");
132         Properties props3 = new Properties();
133         props3.setProperty("test.name", "with XML nano element (standard=false, custom=true)");
Configuration.useInstantProperty(XMLFormatter.class)134         props3.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "false");
Configuration.useInstantProperty(CustomXMLFormatter.class)135         props3.setProperty(Configuration.useInstantProperty(CustomXMLFormatter.class), "true");
136 
137         properties = Collections.unmodifiableList(Arrays.asList(
138                     props1,
139                     props2));
140     }
141 
main(String[] args)142     public static void main(String[] args) throws Exception {
143         Locale.setDefault(Locale.ENGLISH);
144         properties.stream().forEach(XmlFormatterNanos::test);
145     }
146 
getNanoAdjustment(LogRecord record)147     static int getNanoAdjustment(LogRecord record) {
148         return record.getInstant().getNano() % NANOS_IN_MILLI;
149     }
setNanoAdjustment(LogRecord record, int nanos)150     static void setNanoAdjustment(LogRecord record, int nanos) {
151         record.setInstant(Instant.ofEpochSecond(record.getInstant().getEpochSecond(),
152                 (record.getInstant().getNano() / NANOS_IN_MILLI) * NANOS_IN_MILLI + nanos));
153     }
154 
test(Properties props)155     public static void test(Properties props) {
156         Configuration conf = Configuration.apply(props);
157 
158         LogRecord record = new LogRecord(Level.INFO, "Test Name: {0}");
159         record.setLoggerName("test");
160         record.setParameters(new Object[] {conf.testName()});
161         int nanos = record.getInstant().getNano() % NANOS_IN_MILLI;
162         long millis = record.getMillis();
163         // make sure we don't have leading zeros when printing below
164         // the second precision
165         if (millis % MILLIS_IN_SECOND < 100) millis = millis + 100;
166         // make sure we some nanos - and make sure we don't have
167         // trailing zeros
168         if (nanos % 10 == 0) nanos = nanos + 7;
169 
170         record.setMillis(millis);
171         setNanoAdjustment(record, nanos);
172         final Instant instant = record.getInstant();
173         if (nanos < 0) {
174             throw new RuntimeException("Unexpected negative nano adjustment: "
175                     + getNanoAdjustment(record));
176         }
177         if (nanos >= NANOS_IN_MILLI) {
178             throw new RuntimeException("Nano adjustment exceeds 1ms: "
179                     + getNanoAdjustment(record));
180         }
181         if (millis != record.getMillis()) {
182             throw new RuntimeException("Unexpected millis: " + millis + " != "
183                     + record.getMillis());
184         }
185         if (millis != record.getInstant().toEpochMilli()) {
186             throw new RuntimeException("Unexpected millis: "
187                     + record.getInstant().toEpochMilli());
188         }
189         long expectedNanos = (millis % MILLIS_IN_SECOND) * NANOS_IN_MILLI + nanos;
190         assertEquals(expectedNanos, instant.getNano(), "Instant.getNano()");
191 
192         XMLFormatter formatter = new XMLFormatter();
193         testMatching(formatter, record, instant, expectedNanos, conf.useInstant(formatter));
194 
195         XMLFormatter custom = new CustomXMLFormatter();
196         testMatching(custom, record, instant, expectedNanos, conf.useInstant(custom));
197     }
198 
testMatching(XMLFormatter formatter, LogRecord record, Instant instant, long expectedNanos, boolean useInstant)199     private static void testMatching(XMLFormatter formatter,
200             LogRecord record,  Instant instant, long expectedNanos,
201             boolean useInstant) {
202 
203         ZonedDateTime zdt = ZonedDateTime.ofInstant(instant, ZoneId.systemDefault());
204         int zdtNanos = zdt.getNano();
205         assertEquals(expectedNanos, zdtNanos, "ZonedDateTime.getNano()");
206 
207         String str = formatter.format(record);
208 
209         String match = "."+expectedNanos;
210         if (str.contains(match) != useInstant) {
211             throw new RuntimeException(formatter.getClass().getSimpleName()
212                     + ".format()"
213                     + " string does not contain expected nanos: "
214                     + "\n\texpected match for: '" + match + "'"
215                     + "\n\tin: \n" + str);
216         }
217         System.out.println("Found expected match for '"+match+"' in \n"+str);
218 
219         match = "<millis>"+instant.toEpochMilli()+"</millis>";
220         if (!str.contains(match)) {
221             throw new RuntimeException(formatter.getClass().getSimpleName()
222                     + ".format()"
223                     + " string does not contain expected millis: "
224                     + "\n\texpected match for: '" + match + "'"
225                     + "\n\tin: \n" + str);
226         }
227         System.out.println("Found expected match for '"+match+"' in \n"+str);
228 
229         match = "<nanos>";
230         if (str.contains(match) != useInstant) {
231             throw new RuntimeException(formatter.getClass().getSimpleName()
232                     + ".format()"
233                     + " string "
234                     + (useInstant
235                             ? "does not contain expected nanos: "
236                             : "contains unexpected nanos: ")
237                     + "\n\t" + (useInstant ? "expected" : "unexpected")
238                     + " match for: '" + match + "'"
239                     + "\n\tin: \n" + str);
240         }
241         match = "<nanos>"+getNanoAdjustment(record)+"</nanos>";
242         if (str.contains(match) != useInstant) {
243             throw new RuntimeException(formatter.getClass().getSimpleName()
244                     + ".format()"
245                     + " string "
246                     + (useInstant
247                             ? "does not contain expected nanos: "
248                             : "contains unexpected nanos: ")
249                     + "\n\t" + (useInstant ? "expected" : "unexpected")
250                     + " match for: '" + match + "'"
251                     + "\n\tin: \n" + str);
252         }
253         if (useInstant) {
254             System.out.println("Found expected match for '"+match+"' in \n"+str);
255         } else {
256             System.out.println("As expected '"+match+"' is not present in \n"+str);
257         }
258 
259         match = useInstant ? DateTimeFormatter.ISO_INSTANT.format(instant)
260                 : zdt.truncatedTo(ChronoUnit.SECONDS)
261                         .format(DateTimeFormatter.ISO_LOCAL_DATE_TIME);
262         match = "<date>"+match+"</date>";
263         if (!str.contains(match)) {
264             throw new RuntimeException(formatter.getClass().getSimpleName()
265                     + ".format()"
266                     + " string does not contain expected date: "
267                     + "\n\texpected match for: '" + match + "'"
268                     + "\n\tin: \n" + str);
269         }
270         System.out.println("Found expected match for '"+match+"' in \n"+str);
271 
272     }
273 
274 }
275