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 */
23import java.io.ByteArrayInputStream;
24import java.io.ByteArrayOutputStream;
25import java.io.IOException;
26import java.time.Instant;
27import java.time.ZoneId;
28import java.time.ZonedDateTime;
29import java.time.format.DateTimeFormatter;
30import java.time.temporal.ChronoUnit;
31import java.util.Arrays;
32import java.util.Collections;
33import java.util.List;
34import java.util.Locale;
35import java.util.Objects;
36import java.util.Properties;
37import java.util.logging.Level;
38import java.util.logging.LogManager;
39import java.util.logging.LogRecord;
40import 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 */
50public 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 {
60        TestAssertException(String msg) { super(msg); }
61    }
62
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
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;
87        private Configuration(Properties properties) {
88            propertyFile = properties;
89        }
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
102        public static String useInstantProperty(Class<?> type) {
103            return type.getName()+".useInstant";
104        }
105
106        public boolean useInstant(XMLFormatter formatter) {
107            return Boolean.parseBoolean(propertyFile.getProperty(
108                    formatter.getClass().getName()+".useInstant", "true"));
109        }
110
111        public String testName() {
112            return propertyFile.getProperty("test.name", "????");
113        }
114
115        public static Configuration of(Properties props) {
116            return new Configuration(props);
117        }
118
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)");
130        props2.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "true");
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)");
134        props3.setProperty(Configuration.useInstantProperty(XMLFormatter.class), "false");
135        props3.setProperty(Configuration.useInstantProperty(CustomXMLFormatter.class), "true");
136
137        properties = Collections.unmodifiableList(Arrays.asList(
138                    props1,
139                    props2));
140    }
141
142    public static void main(String[] args) throws Exception {
143        Locale.setDefault(Locale.ENGLISH);
144        properties.stream().forEach(XmlFormatterNanos::test);
145    }
146
147    static int getNanoAdjustment(LogRecord record) {
148        return record.getInstant().getNano() % NANOS_IN_MILLI;
149    }
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
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
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