001// License: GPL. For details, see LICENSE file.
002package org.openstreetmap.josm.tools;
003
004import static org.openstreetmap.josm.tools.I18n.tr;
005
006import java.io.OutputStream;
007import java.io.PrintWriter;
008import java.io.StringWriter;
009import java.io.UnsupportedEncodingException;
010import java.text.MessageFormat;
011import java.util.ArrayList;
012import java.util.Arrays;
013import java.util.List;
014import java.util.Locale;
015import java.util.function.Supplier;
016import java.util.logging.ConsoleHandler;
017import java.util.logging.Handler;
018import java.util.logging.Level;
019import java.util.logging.LogRecord;
020import java.util.logging.Logger;
021
022import org.openstreetmap.josm.tools.bugreport.BugReport;
023
024/**
025 * This class contains utility methods to log errors and warnings.
026 * <p>
027 * There are multiple log levels supported.
028 * @author Michael Zangl
029 * @since 10899
030 */
031public final class Logging {
032    /**
033     * The josm internal log level indicating a severe error in the application that usually leads to a crash.
034     */
035    public static final Level LEVEL_ERROR = Level.SEVERE;
036    /**
037     * The josm internal log level to use when something that may lead to a crash or wrong behaviour has happened.
038     */
039    public static final Level LEVEL_WARN = Level.WARNING;
040    /**
041     * The josm internal log level to use for important events that will be useful when debugging problems
042     */
043    public static final Level LEVEL_INFO = Level.INFO;
044    /**
045     * The josm internal log level to print debug output
046     */
047    public static final Level LEVEL_DEBUG = Level.FINE;
048    /**
049     * The finest log level josm supports. This lets josm print a lot of debug output.
050     */
051    public static final Level LEVEL_TRACE = Level.FINEST;
052    private static final Logger LOGGER = Logger.getAnonymousLogger();
053    private static final RememberWarningHandler WARNINGS = new RememberWarningHandler();
054    private static final Stopwatch startup = Stopwatch.createStarted();
055
056    /**
057     * A {@link ConsoleHandler} with a couple of extra features, allowing it to be targeted at an
058     * an arbitrary {@link OutputStream} which it can be asked to reacquire the reference for on demand
059     * through {@link #reacquireOutputStream()}. It can also prevent a LogRecord's output if a
060     * specified {@code prioritizedHandler} would have outputted it.
061     * @since 14052
062     */
063    public static class ReacquiringConsoleHandler extends ConsoleHandler {
064        private final Supplier<OutputStream> outputStreamSupplier;
065        private final Handler prioritizedHandler;
066        private OutputStream outputStreamMemo;
067        /**
068         * This variables is set to true as soon as the superconstructor has completed.
069         * The superconstructor calls {@code setOutputStream(System.err)}, any subsequent call of
070         * {@link #setOutputStream(OutputStream)} would then flush and close {@link System#err}. To avoid this,
071         * we override {@link #setOutputStream(OutputStream)} to completely ignore all calls from the superconstructor.
072         */
073        private final boolean superCompleted;
074
075        /**
076        * Construct a new {@link ReacquiringConsoleHandler}.
077        * @param outputStreamSupplier A {@link Supplier} which will return the desired
078        *   {@link OutputStream} for this handler when called. Particularly useful if you happen to be
079        *   using a test framework which will switch out references to the stderr/stdout streams with
080        *   new dummy ones from time to time.
081        * @param prioritizedHandler If non-null, will suppress output of any log records which pass this
082        *   handler's {@code Handler#isLoggable(LogRecord)} method.
083        */
084        public ReacquiringConsoleHandler(
085            final Supplier<OutputStream> outputStreamSupplier,
086            final Handler prioritizedHandler
087        ) {
088            super();
089            superCompleted = true;
090            this.outputStreamSupplier = outputStreamSupplier;
091            this.prioritizedHandler = prioritizedHandler;
092
093            try {
094                // Make sure we use the correct console encoding on Windows
095                this.setEncoding(System.getProperty("sun.stdout.encoding"));
096            } catch (SecurityException | UnsupportedEncodingException e) {
097                System.err.println(e);
098            }
099            this.reacquireOutputStream();
100        }
101
102        /**
103         * Set output stream to one acquired from calling outputStreamSupplier
104         */
105        public synchronized void reacquireOutputStream() {
106            final OutputStream reacquiredStream = this.outputStreamSupplier.get(); // NOPMD
107
108            // only bother calling setOutputStream if it's actually different, as setOutputStream
109            // has the nasty side effect of closing any previous output stream, which is certainly not
110            // what we would want were the new stream the same one
111            if (reacquiredStream != this.outputStreamMemo) {
112                this.setOutputStream(reacquiredStream);
113            }
114        }
115
116        @Override
117        public synchronized void setOutputStream(final OutputStream outputStream) {
118            // Ignore calls from superconstructor (see javadoc of the variable for details)
119            if (superCompleted) {
120                // this wouldn't be necessary if StreamHandler made it possible to see what the current
121                // output stream is set to
122                this.outputStreamMemo = outputStream;
123                try {
124                    super.setOutputStream(outputStream);
125                } catch (SecurityException e) {
126                    System.err.println("Unable to set logging output stream: " + e.getMessage());
127                }
128            }
129        }
130
131        @Override
132        public synchronized void publish(LogRecord record) {
133            if (this.prioritizedHandler == null || !this.prioritizedHandler.isLoggable(record)) {
134                super.publish(record);
135            }
136        }
137    }
138
139    static {
140        // We need to be sure java.locale.providers system property is initialized by JOSM, not by JRE
141        // The call to ConsoleHandler constructor makes the JRE access this property by side effect
142        I18n.setupJavaLocaleProviders();
143
144        LOGGER.setLevel(Level.ALL);
145        LOGGER.setUseParentHandlers(false);
146
147        // for a more concise logging output via java.util.logging.SimpleFormatter
148        Utils.updateSystemProperty("java.util.logging.SimpleFormatter.format", "%1$tF %1$tT.%1$tL %4$s: %5$s%6$s%n");
149
150        ConsoleHandler stderr = new ReacquiringConsoleHandler(() -> System.err, null);
151        LOGGER.addHandler(stderr);
152        try {
153            stderr.setLevel(LEVEL_WARN);
154        } catch (SecurityException e) {
155            System.err.println("Unable to set logging level: " + e.getMessage());
156        }
157
158        ConsoleHandler stdout = new ReacquiringConsoleHandler(() -> System.out, stderr);
159        LOGGER.addHandler(stdout);
160        try {
161            stdout.setLevel(Level.ALL);
162        } catch (SecurityException e) {
163            System.err.println("Unable to set logging level: " + e.getMessage());
164        }
165
166        LOGGER.addHandler(WARNINGS);
167        // Set log level to info, otherwise the first ListenerList created will be for debugging purposes and create memory leaks
168        Logging.setLogLevel(Logging.LEVEL_INFO);
169    }
170
171    private Logging() {
172        // hide
173    }
174
175    /**
176     * Set the global log level.
177     * @param level The log level to use
178     */
179    public static void setLogLevel(Level level) {
180        LOGGER.setLevel(level);
181    }
182
183    /**
184     * Prints an error message if logging is on.
185     * @param message The message to print.
186     */
187    public static void error(String message) {
188        logPrivate(LEVEL_ERROR, message);
189    }
190
191    /**
192     * Prints a formatted error message if logging is on. Calls {@link MessageFormat#format}
193     * function to format text.
194     * @param pattern The formatted message to print.
195     * @param args The objects to insert into format string.
196     */
197    public static void error(String pattern, Object... args) {
198        logPrivate(LEVEL_ERROR, pattern, args);
199    }
200
201    /**
202     * Prints an error message for the given Throwable if logging is on.
203     * @param t The throwable object causing the error.
204     * @since 12620
205     */
206    public static void error(Throwable t) {
207        logWithStackTrace(Logging.LEVEL_ERROR, t);
208    }
209
210    /**
211     * Prints a warning message if logging is on.
212     * @param message The message to print.
213     */
214    public static void warn(String message) {
215        logPrivate(LEVEL_WARN, message);
216    }
217
218    /**
219     * Prints a formatted warning message if logging is on. Calls {@link MessageFormat#format}
220     * function to format text.
221     * @param pattern The formatted message to print.
222     * @param args The objects to insert into format string.
223     */
224    public static void warn(String pattern, Object... args) {
225        logPrivate(LEVEL_WARN, pattern, args);
226    }
227
228    /**
229     * Prints a warning message for the given Throwable if logging is on.
230     * @param t The throwable object causing the error.
231     * @since 12620
232     */
233    public static void warn(Throwable t) {
234        logWithStackTrace(Logging.LEVEL_WARN, t);
235    }
236
237    /**
238     * Prints a info message if logging is on.
239     * @param message The message to print.
240     */
241    public static void info(String message) {
242        logPrivate(LEVEL_INFO, message);
243    }
244
245    /**
246     * Prints a formatted info message if logging is on. Calls {@link MessageFormat#format}
247     * function to format text.
248     * @param pattern The formatted message to print.
249     * @param args The objects to insert into format string.
250     */
251    public static void info(String pattern, Object... args) {
252        logPrivate(LEVEL_INFO, pattern, args);
253    }
254
255    /**
256     * Prints a info message for the given Throwable if logging is on.
257     * @param t The throwable object causing the error.
258     * @since 12620
259     */
260    public static void info(Throwable t) {
261        logWithStackTrace(Logging.LEVEL_INFO, t);
262    }
263
264    /**
265     * Prints a debug message if logging is on.
266     * @param message The message to print.
267     */
268    public static void debug(String message) {
269        logPrivate(LEVEL_DEBUG, message);
270    }
271
272    /**
273     * Prints a formatted debug message if logging is on. Calls {@link MessageFormat#format}
274     * function to format text.
275     * @param pattern The formatted message to print.
276     * @param args The objects to insert into format string.
277     */
278    public static void debug(String pattern, Object... args) {
279        logPrivate(LEVEL_DEBUG, pattern, args);
280    }
281
282    /**
283     * Prints a debug message for the given Throwable if logging is on.
284     * @param t The throwable object causing the error.
285     * @since 12620
286     */
287    public static void debug(Throwable t) {
288        log(Logging.LEVEL_DEBUG, t);
289    }
290
291    /**
292     * Prints a trace message if logging is on.
293     * @param message The message to print.
294     */
295    public static void trace(String message) {
296        logPrivate(LEVEL_TRACE, message);
297    }
298
299    /**
300     * Prints a formatted trace message if logging is on. Calls {@link MessageFormat#format}
301     * function to format text.
302     * @param pattern The formatted message to print.
303     * @param args The objects to insert into format string.
304     */
305    public static void trace(String pattern, Object... args) {
306        logPrivate(LEVEL_TRACE, pattern, args);
307    }
308
309    /**
310     * Prints a trace message for the given Throwable if logging is on.
311     * @param t The throwable object causing the error.
312     * @since 12620
313     */
314    public static void trace(Throwable t) {
315        log(Logging.LEVEL_TRACE, t);
316    }
317
318    /**
319     * Logs a throwable that happened. The stack trace is not added to the log.
320     * @param level The level.
321     * @param t The throwable that should be logged.
322     * @see #logWithStackTrace(Level, Throwable)
323     */
324    public static void log(Level level, Throwable t) {
325        logPrivate(level, () -> getErrorLog(null, t));
326    }
327
328    /**
329     * Logs a throwable that happened. The stack trace is not added to the log.
330     * @param level The level.
331     * @param message An additional error message
332     * @param t The throwable that caused the message
333     * @see #logWithStackTrace(Level, String, Throwable)
334     */
335    public static void log(Level level, String message, Throwable t) {
336        logPrivate(level, () -> getErrorLog(message, t));
337    }
338
339    /**
340     * Logs a throwable that happened. Adds the stack trace to the log.
341     * @param level The level.
342     * @param t The throwable that should be logged.
343     * @see #log(Level, Throwable)
344     */
345    public static void logWithStackTrace(Level level, Throwable t) {
346        logPrivate(level, () -> getErrorLogWithStack(null, t));
347    }
348
349    /**
350     * Logs a throwable that happened. Adds the stack trace to the log.
351     * @param level The level.
352     * @param message An additional error message
353     * @param t The throwable that should be logged.
354     * @see #logWithStackTrace(Level, Throwable)
355     */
356    public static void logWithStackTrace(Level level, String message, Throwable t) {
357        logPrivate(level, () -> getErrorLogWithStack(message, t));
358    }
359
360    /**
361     * Logs a throwable that happened. Adds the stack trace to the log.
362     * @param level The level.
363     * @param t The throwable that should be logged.
364     * @param pattern The formatted message to print.
365     * @param args The objects to insert into format string
366     * @see #logWithStackTrace(Level, Throwable)
367     */
368    public static void logWithStackTrace(Level level, Throwable t, String pattern, Object... args) {
369        logPrivate(level, () -> getErrorLogWithStack(MessageFormat.format(pattern, args), t));
370    }
371
372    private static void logPrivate(Level level, String pattern, Object... args) {
373        logPrivate(level, () -> MessageFormat.format(pattern, args));
374    }
375
376    private static void logPrivate(Level level, String message) {
377        logPrivate(level, () -> message);
378    }
379
380    private static void logPrivate(Level level, Supplier<String> supplier) {
381        // all log methods immediately call one of the logPrivate methods.
382        if (LOGGER.isLoggable(level)) {
383            StackTraceElement callingMethod = BugReport.getCallingMethod(1, Logging.class.getName(), name -> !"logPrivate".equals(name));
384            LOGGER.logp(level, callingMethod.getClassName(), callingMethod.getMethodName(), supplier);
385        }
386    }
387
388    /**
389     * Tests if a given log level is enabled. This can be used to avoid constructing debug data if required.
390     *
391     * For formatting text, you should use the {@link #debug(String, Object...)} message
392     * @param level A level constant. You can e.g. use {@link Logging#LEVEL_ERROR}
393     * @return <code>true</code> if log level is enabled.
394     */
395    public static boolean isLoggingEnabled(Level level) {
396        return LOGGER.isLoggable(level);
397    }
398
399    /**
400     * Determines if debug log level is enabled.
401     * Useful to avoid costly construction of debug messages when not enabled.
402     * @return {@code true} if log level is at least debug, {@code false} otherwise
403     * @since 12620
404     */
405    public static boolean isDebugEnabled() {
406        return isLoggingEnabled(Logging.LEVEL_DEBUG);
407    }
408
409    /**
410     * Determines if trace log level is enabled.
411     * Useful to avoid costly construction of trace messages when not enabled.
412     * @return {@code true} if log level is at least trace, {@code false} otherwise
413     * @since 12620
414     */
415    public static boolean isTraceEnabled() {
416        return isLoggingEnabled(Logging.LEVEL_TRACE);
417    }
418
419    private static String getErrorLog(String message, Throwable t) {
420        StringBuilder sb = new StringBuilder();
421        if (message != null) {
422            sb.append(message).append(": ");
423        }
424        sb.append(getErrorMessage(t));
425        return sb.toString();
426    }
427
428    private static String getErrorLogWithStack(String message, Throwable t) {
429        StringWriter sb = new StringWriter();
430        sb.append(getErrorLog(message, t));
431        if (t != null) {
432            sb.append('\n');
433            t.printStackTrace(new PrintWriter(sb));
434        }
435        return sb.toString();
436    }
437
438    /**
439     * Returns a human-readable message of error, also usable for developers.
440     * @param t The error
441     * @return The human-readable error message
442     */
443    public static String getErrorMessage(Throwable t) {
444        if (t == null) {
445            return "(no error)";
446        }
447        StringBuilder sb = new StringBuilder(t.getClass().getName());
448        String msg = t.getMessage();
449        if (msg != null) {
450            sb.append(": ").append(msg.trim());
451        }
452        Throwable cause = t.getCause();
453        if (cause != null && !cause.equals(t)) {
454            // this may cause infinite loops in the unlikely case that there is a loop in the causes.
455            sb.append(". ").append(tr("Cause: ")).append(getErrorMessage(cause));
456        }
457        return sb.toString();
458    }
459
460    /**
461     * Clear the list of last warnings
462     */
463    public static void clearLastErrorAndWarnings() {
464        WARNINGS.clear();
465    }
466
467    /**
468     * Get the last error and warning messages in the order in which they were received.
469     * @return The last errors and warnings.
470     */
471    public static List<String> getLastErrorAndWarnings() {
472        return WARNINGS.getMessages();
473    }
474
475    /**
476     * Provides direct access to the logger used. Use of methods like {@link #warn(String)} is preferred.
477     * @return The logger
478     */
479    public static Logger getLogger() {
480        return LOGGER;
481    }
482
483    private static class RememberWarningHandler extends Handler {
484        private final String[] log = new String[10];
485        private int messagesLogged;
486
487        synchronized void clear() {
488            messagesLogged = 0;
489            Arrays.fill(log, null);
490        }
491
492        @Override
493        public synchronized void publish(LogRecord record) {
494            // We don't use setLevel + isLoggable to work in WebStart Sandbox mode
495            if (record.getLevel().intValue() < LEVEL_WARN.intValue()) {
496                return;
497            }
498
499            String msg = String.format(Locale.ROOT, "%09.3f %s%s", startup.elapsed() / 1000., getPrefix(record), record.getMessage());
500
501            // Only remember first line of message
502            int idx = msg.indexOf('\n');
503            if (idx > 0) {
504                msg = msg.substring(0, idx);
505            }
506            log[messagesLogged % log.length] = msg;
507            messagesLogged++;
508        }
509
510        private static String getPrefix(LogRecord record) {
511            if (record.getLevel().equals(LEVEL_WARN)) {
512                return "W: ";
513            } else {
514                // worse than warn
515                return "E: ";
516            }
517        }
518
519        synchronized List<String> getMessages() {
520            List<String> logged = Arrays.asList(log);
521            ArrayList<String> res = new ArrayList<>();
522            int logOffset = messagesLogged % log.length;
523            if (messagesLogged > logOffset) {
524                res.addAll(logged.subList(logOffset, log.length));
525            }
526            res.addAll(logged.subList(0, logOffset));
527            return res;
528        }
529
530        @Override
531        public synchronized void flush() {
532            // nothing to do
533        }
534
535        @Override
536        public void close() {
537            // nothing to do
538        }
539    }
540}