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}