| OLD | NEW |
| (Empty) |
| 1 // Copyright (c) 2012, the Dart project authors. Please see the AUTHORS file | |
| 2 // for details. All rights reserved. Use of this source code is governed by a | |
| 3 // BSD-style license that can be found in the LICENSE file. | |
| 4 | |
| 5 /// Message logging. | |
| 6 library pub.log; | |
| 7 | |
| 8 import 'dart:async'; | |
| 9 import 'dart:convert'; | |
| 10 import 'dart:io'; | |
| 11 | |
| 12 import 'package:args/command_runner.dart'; | |
| 13 import 'package:path/path.dart' as p; | |
| 14 import 'package:source_span/source_span.dart'; | |
| 15 import 'package:stack_trace/stack_trace.dart'; | |
| 16 | |
| 17 import 'exceptions.dart'; | |
| 18 import 'io.dart'; | |
| 19 import 'progress.dart'; | |
| 20 import 'transcript.dart'; | |
| 21 import 'utils.dart'; | |
| 22 | |
| 23 /// The singleton instance so that we can have a nice api like: | |
| 24 /// | |
| 25 /// log.json.error(...); | |
| 26 final json = new _JsonLogger(); | |
| 27 | |
| 28 /// The current logging verbosity. | |
| 29 Verbosity verbosity = Verbosity.NORMAL; | |
| 30 | |
| 31 /// Whether or not to log entries with prejudice. | |
| 32 bool withPrejudice = false; | |
| 33 | |
| 34 /// In cases where there's a ton of log spew, make sure we don't eat infinite | |
| 35 /// memory. | |
| 36 /// | |
| 37 /// This can occur when the backtracking solver stumbles into a pathological | |
| 38 /// dependency graph. It generally will find a solution, but it may log | |
| 39 /// thousands and thousands of entries to get there. | |
| 40 const _MAX_TRANSCRIPT = 10000; | |
| 41 | |
| 42 /// The list of recorded log messages. Will only be recorded if | |
| 43 /// [recordTranscript()] is called. | |
| 44 Transcript<Entry> _transcript; | |
| 45 | |
| 46 /// The currently-animated progress indicator, if any. | |
| 47 /// | |
| 48 /// This will also be in [_progresses]. | |
| 49 Progress _animatedProgress; | |
| 50 | |
| 51 final _cyan = getSpecial('\u001b[36m'); | |
| 52 final _green = getSpecial('\u001b[32m'); | |
| 53 final _magenta = getSpecial('\u001b[35m'); | |
| 54 final _red = getSpecial('\u001b[31m'); | |
| 55 final _yellow = getSpecial('\u001b[33m'); | |
| 56 final _gray = getSpecial('\u001b[1;30m'); | |
| 57 final _none = getSpecial('\u001b[0m'); | |
| 58 final _noColor = getSpecial('\u001b[39m'); | |
| 59 final _bold = getSpecial('\u001b[1m'); | |
| 60 | |
| 61 /// An enum type for defining the different logging levels a given message can | |
| 62 /// be associated with. | |
| 63 /// | |
| 64 /// By default, [ERROR] and [WARNING] messages are printed to sterr. [MESSAGE] | |
| 65 /// messages are printed to stdout, and others are ignored. | |
| 66 class Level { | |
| 67 /// An error occurred and an operation could not be completed. | |
| 68 /// | |
| 69 /// Usually shown to the user on stderr. | |
| 70 static const ERROR = const Level._("ERR "); | |
| 71 | |
| 72 /// Something unexpected happened, but the program was able to continue, | |
| 73 /// though possibly in a degraded fashion. | |
| 74 static const WARNING = const Level._("WARN"); | |
| 75 | |
| 76 /// A message intended specifically to be shown to the user. | |
| 77 static const MESSAGE = const Level._("MSG "); | |
| 78 | |
| 79 /// Some interaction with the external world occurred, such as a network | |
| 80 /// operation, process spawning, or file IO. | |
| 81 static const IO = const Level._("IO "); | |
| 82 | |
| 83 /// Incremental output during pub's version constraint solver. | |
| 84 static const SOLVER = const Level._("SLVR"); | |
| 85 | |
| 86 /// Fine-grained and verbose additional information. | |
| 87 /// | |
| 88 /// Used to provide program state context for other logs (such as what pub | |
| 89 /// was doing when an IO operation occurred) or just more detail for an | |
| 90 /// operation. | |
| 91 static const FINE = const Level._("FINE"); | |
| 92 | |
| 93 const Level._(this.name); | |
| 94 final String name; | |
| 95 | |
| 96 String toString() => name; | |
| 97 } | |
| 98 | |
| 99 typedef _LogFn(Entry entry); | |
| 100 | |
| 101 /// An enum type to control which log levels are displayed and how they are | |
| 102 /// displayed. | |
| 103 class Verbosity { | |
| 104 /// Silence all logging. | |
| 105 static const NONE = const Verbosity._("none", const { | |
| 106 Level.ERROR: null, | |
| 107 Level.WARNING: null, | |
| 108 Level.MESSAGE: null, | |
| 109 Level.IO: null, | |
| 110 Level.SOLVER: null, | |
| 111 Level.FINE: null | |
| 112 }); | |
| 113 | |
| 114 /// Shows only errors and warnings. | |
| 115 static const WARNING = const Verbosity._("warning", const { | |
| 116 Level.ERROR: _logToStderr, | |
| 117 Level.WARNING: _logToStderr, | |
| 118 Level.MESSAGE: null, | |
| 119 Level.IO: null, | |
| 120 Level.SOLVER: null, | |
| 121 Level.FINE: null | |
| 122 }); | |
| 123 | |
| 124 /// The default verbosity which shows errors, warnings, and messages. | |
| 125 static const NORMAL = const Verbosity._("normal", const { | |
| 126 Level.ERROR: _logToStderr, | |
| 127 Level.WARNING: _logToStderr, | |
| 128 Level.MESSAGE: _logToStdout, | |
| 129 Level.IO: null, | |
| 130 Level.SOLVER: null, | |
| 131 Level.FINE: null | |
| 132 }); | |
| 133 | |
| 134 /// Shows errors, warnings, messages, and IO event logs. | |
| 135 static const IO = const Verbosity._("io", const { | |
| 136 Level.ERROR: _logToStderrWithLabel, | |
| 137 Level.WARNING: _logToStderrWithLabel, | |
| 138 Level.MESSAGE: _logToStdoutWithLabel, | |
| 139 Level.IO: _logToStderrWithLabel, | |
| 140 Level.SOLVER: null, | |
| 141 Level.FINE: null | |
| 142 }); | |
| 143 | |
| 144 /// Shows errors, warnings, messages, and version solver logs. | |
| 145 static const SOLVER = const Verbosity._("solver", const { | |
| 146 Level.ERROR: _logToStderr, | |
| 147 Level.WARNING: _logToStderr, | |
| 148 Level.MESSAGE: _logToStdout, | |
| 149 Level.IO: null, | |
| 150 Level.SOLVER: _logToStdout, | |
| 151 Level.FINE: null | |
| 152 }); | |
| 153 | |
| 154 /// Shows all logs. | |
| 155 static const ALL = const Verbosity._("all", const { | |
| 156 Level.ERROR: _logToStderrWithLabel, | |
| 157 Level.WARNING: _logToStderrWithLabel, | |
| 158 Level.MESSAGE: _logToStdoutWithLabel, | |
| 159 Level.IO: _logToStderrWithLabel, | |
| 160 Level.SOLVER: _logToStderrWithLabel, | |
| 161 Level.FINE: _logToStderrWithLabel | |
| 162 }); | |
| 163 | |
| 164 const Verbosity._(this.name, this._loggers); | |
| 165 final String name; | |
| 166 final Map<Level, _LogFn> _loggers; | |
| 167 | |
| 168 /// Returns whether or not logs at [level] will be printed. | |
| 169 bool isLevelVisible(Level level) => _loggers[level] != null; | |
| 170 | |
| 171 String toString() => name; | |
| 172 } | |
| 173 | |
| 174 /// A single log entry. | |
| 175 class Entry { | |
| 176 final Level level; | |
| 177 final List<String> lines; | |
| 178 | |
| 179 Entry(this.level, this.lines); | |
| 180 } | |
| 181 | |
| 182 /// Logs [message] at [Level.ERROR]. | |
| 183 /// | |
| 184 /// If [error] is passed, it's appended to [message]. If [trace] is passed, it's | |
| 185 /// printed at log level fine. | |
| 186 void error(message, [error, StackTrace trace]) { | |
| 187 if (error != null) { | |
| 188 message = "$message: $error"; | |
| 189 if (error is Error && trace == null) trace = error.stackTrace; | |
| 190 } | |
| 191 write(Level.ERROR, message); | |
| 192 if (trace != null) write(Level.FINE, new Chain.forTrace(trace)); | |
| 193 } | |
| 194 | |
| 195 /// Logs [message] at [Level.WARNING]. | |
| 196 void warning(message) => write(Level.WARNING, message); | |
| 197 | |
| 198 /// Logs [message] at [Level.MESSAGE]. | |
| 199 void message(message) => write(Level.MESSAGE, message); | |
| 200 | |
| 201 /// Logs [message] at [Level.IO]. | |
| 202 void io(message) => write(Level.IO, message); | |
| 203 | |
| 204 /// Logs [message] at [Level.SOLVER]. | |
| 205 void solver(message) => write(Level.SOLVER, message); | |
| 206 | |
| 207 /// Logs [message] at [Level.FINE]. | |
| 208 void fine(message) => write(Level.FINE, message); | |
| 209 | |
| 210 /// Logs [message] at [level]. | |
| 211 void write(Level level, message) { | |
| 212 message = message.toString(); | |
| 213 var lines = splitLines(message); | |
| 214 | |
| 215 // Discard a trailing newline. This is useful since StringBuffers often end | |
| 216 // up with an extra newline at the end from using [writeln]. | |
| 217 if (lines.isNotEmpty && lines.last == "") { | |
| 218 lines.removeLast(); | |
| 219 } | |
| 220 | |
| 221 var entry = new Entry(level, lines.map(format).toList()); | |
| 222 | |
| 223 var logFn = verbosity._loggers[level]; | |
| 224 if (logFn != null) logFn(entry); | |
| 225 | |
| 226 if (_transcript != null) _transcript.add(entry); | |
| 227 } | |
| 228 | |
| 229 final _capitalizedAnsiEscape = new RegExp(r'\u001b\[\d+(;\d+)?M'); | |
| 230 | |
| 231 /// Returns [string] formatted as it would be if it were logged. | |
| 232 String format(String string) { | |
| 233 if (!withPrejudice) return string; | |
| 234 | |
| 235 // [toUpperCase] can corrupt terminal colorings, so fix them up using | |
| 236 // [replaceAllMapped]. | |
| 237 string = string.toUpperCase().replaceAllMapped( | |
| 238 _capitalizedAnsiEscape, | |
| 239 (match) => match[0].toLowerCase()); | |
| 240 | |
| 241 // Don't use [bold] because it's disabled under [withPrejudice]. | |
| 242 return "$_bold$string$_none"; | |
| 243 } | |
| 244 | |
| 245 /// Logs an asynchronous IO operation. | |
| 246 /// | |
| 247 /// Logs [startMessage] before the operation starts, then when [operation] | |
| 248 /// completes, invokes [endMessage] with the completion value and logs the | |
| 249 /// result of that. Returns a future that completes after the logging is done. | |
| 250 /// | |
| 251 /// If [endMessage] is omitted, then logs "Begin [startMessage]" before the | |
| 252 /// operation and "End [startMessage]" after it. | |
| 253 Future ioAsync(String startMessage, Future operation, [String | |
| 254 endMessage(value)]) { | |
| 255 if (endMessage == null) { | |
| 256 io("Begin $startMessage."); | |
| 257 } else { | |
| 258 io(startMessage); | |
| 259 } | |
| 260 | |
| 261 return operation.then((result) { | |
| 262 if (endMessage == null) { | |
| 263 io("End $startMessage."); | |
| 264 } else { | |
| 265 io(endMessage(result)); | |
| 266 } | |
| 267 return result; | |
| 268 }); | |
| 269 } | |
| 270 | |
| 271 /// Logs the spawning of an [executable] process with [arguments] at [IO] | |
| 272 /// level. | |
| 273 void process(String executable, List<String> arguments, String workingDirectory) | |
| 274 { | |
| 275 io( | |
| 276 "Spawning \"$executable ${arguments.join(' ')}\" in " | |
| 277 "${p.absolute(workingDirectory)}"); | |
| 278 } | |
| 279 | |
| 280 /// Logs the results of running [executable]. | |
| 281 void processResult(String executable, PubProcessResult result) { | |
| 282 // Log it all as one message so that it shows up as a single unit in the logs. | |
| 283 var buffer = new StringBuffer(); | |
| 284 buffer.writeln("Finished $executable. Exit code ${result.exitCode}."); | |
| 285 | |
| 286 dumpOutput(String name, List<String> output) { | |
| 287 if (output.length == 0) { | |
| 288 buffer.writeln("Nothing output on $name."); | |
| 289 } else { | |
| 290 buffer.writeln("$name:"); | |
| 291 var numLines = 0; | |
| 292 for (var line in output) { | |
| 293 if (++numLines > 1000) { | |
| 294 buffer.writeln( | |
| 295 '[${output.length - 1000}] more lines of output ' 'truncated...]')
; | |
| 296 break; | |
| 297 } | |
| 298 | |
| 299 buffer.writeln("| $line"); | |
| 300 } | |
| 301 } | |
| 302 } | |
| 303 | |
| 304 dumpOutput("stdout", result.stdout); | |
| 305 dumpOutput("stderr", result.stderr); | |
| 306 | |
| 307 io(buffer.toString().trim()); | |
| 308 } | |
| 309 | |
| 310 /// Logs an exception. | |
| 311 void exception(exception, [StackTrace trace]) { | |
| 312 if (exception is SilentException) return; | |
| 313 | |
| 314 var chain = trace == null ? new Chain.current() : new Chain.forTrace(trace); | |
| 315 | |
| 316 // This is basically the top-level exception handler so that we don't | |
| 317 // spew a stack trace on our users. | |
| 318 if (exception is SourceSpanException) { | |
| 319 error(exception.toString(color: canUseSpecialChars)); | |
| 320 } else { | |
| 321 error(getErrorMessage(exception)); | |
| 322 } | |
| 323 fine("Exception type: ${exception.runtimeType}"); | |
| 324 | |
| 325 if (json.enabled) { | |
| 326 if (exception is UsageException) { | |
| 327 // Don't print usage info in JSON output. | |
| 328 json.error(exception.message); | |
| 329 } else { | |
| 330 json.error(exception); | |
| 331 } | |
| 332 } | |
| 333 | |
| 334 if (!isUserFacingException(exception)) { | |
| 335 error(chain.terse); | |
| 336 } else { | |
| 337 fine(chain.terse); | |
| 338 } | |
| 339 | |
| 340 if (exception is WrappedException && exception.innerError != null) { | |
| 341 var message = "Wrapped exception: ${exception.innerError}"; | |
| 342 if (exception.innerChain != null) { | |
| 343 message = "$message\n${exception.innerChain}"; | |
| 344 } | |
| 345 fine(message); | |
| 346 } | |
| 347 } | |
| 348 | |
| 349 /// Enables recording of log entries. | |
| 350 void recordTranscript() { | |
| 351 _transcript = new Transcript<Entry>(_MAX_TRANSCRIPT); | |
| 352 } | |
| 353 | |
| 354 /// If [recordTranscript()] was called, then prints the previously recorded log | |
| 355 /// transcript to stderr. | |
| 356 void dumpTranscript() { | |
| 357 if (_transcript == null) return; | |
| 358 | |
| 359 stderr.writeln('---- Log transcript ----'); | |
| 360 _transcript.forEach((entry) { | |
| 361 _printToStream(stderr, entry, showLabel: true); | |
| 362 }, (discarded) { | |
| 363 stderr.writeln('---- ($discarded discarded) ----'); | |
| 364 }); | |
| 365 stderr.writeln('---- End log transcript ----'); | |
| 366 } | |
| 367 | |
| 368 /// Prints [message] then displays an updated elapsed time until the future | |
| 369 /// returned by [callback] completes. | |
| 370 /// | |
| 371 /// If anything else is logged during this (including another call to | |
| 372 /// [progress]) that cancels the progress animation, although the total time | |
| 373 /// will still be printed once it finishes. If [fine] is passed, the progress | |
| 374 /// information will only be visible at [Level.FINE]. | |
| 375 Future progress(String message, Future callback(), {bool fine: false}) { | |
| 376 _stopProgress(); | |
| 377 | |
| 378 var progress = new Progress(message, fine: fine); | |
| 379 _animatedProgress = progress; | |
| 380 return callback().whenComplete(progress.stop); | |
| 381 } | |
| 382 | |
| 383 /// Stops animating the running progress indicator, if currently running. | |
| 384 void _stopProgress() { | |
| 385 if (_animatedProgress != null) _animatedProgress.stopAnimating(); | |
| 386 _animatedProgress = null; | |
| 387 } | |
| 388 | |
| 389 /// The number of outstanding calls to [muteProgress] that have not been unmuted | |
| 390 /// yet. | |
| 391 int _numMutes = 0; | |
| 392 | |
| 393 /// Whether progress animation should be muted or not. | |
| 394 bool get isMuted => _numMutes > 0; | |
| 395 | |
| 396 /// Stops animating any ongoing progress. | |
| 397 /// | |
| 398 /// This is called before spawning Git since Git sometimes writes directly to | |
| 399 /// the terminal to ask for login credentials, which would then get overwritten | |
| 400 /// by the progress animation. | |
| 401 /// | |
| 402 /// Each call to this must be paired with a call to [unmuteProgress]. | |
| 403 void muteProgress() { | |
| 404 _numMutes++; | |
| 405 } | |
| 406 | |
| 407 /// Resumes animating any ongoing progress once all calls to [muteProgress] | |
| 408 /// have made their matching [unmuteProgress]. | |
| 409 void unmuteProgress() { | |
| 410 assert(_numMutes > 0); | |
| 411 _numMutes--; | |
| 412 } | |
| 413 | |
| 414 /// Wraps [text] in the ANSI escape codes to make it bold when on a platform | |
| 415 /// that supports that. | |
| 416 /// | |
| 417 /// Use this to highlight the most important piece of a long chunk of text. | |
| 418 /// | |
| 419 /// This is disabled under [withPrejudice] since all text is bold with | |
| 420 /// prejudice. | |
| 421 String bold(text) => withPrejudice ? text : "$_bold$text$_none"; | |
| 422 | |
| 423 /// Wraps [text] in the ANSI escape codes to make it gray when on a platform | |
| 424 /// that supports that. | |
| 425 /// | |
| 426 /// Use this for text that's less important than the text around it. | |
| 427 /// | |
| 428 /// The gray marker also enables bold, so it needs to be handled specially with | |
| 429 /// [withPrejudice] to avoid disabling bolding entirely. | |
| 430 String gray(text) => | |
| 431 withPrejudice ? "$_gray$text$_noColor" : "$_gray$text$_none"; | |
| 432 | |
| 433 /// Wraps [text] in the ANSI escape codes to color it cyan when on a platform | |
| 434 /// that supports that. | |
| 435 /// | |
| 436 /// Use this to highlight something interesting but neither good nor bad. | |
| 437 String cyan(text) => "$_cyan$text$_noColor"; | |
| 438 | |
| 439 /// Wraps [text] in the ANSI escape codes to color it green when on a platform | |
| 440 /// that supports that. | |
| 441 /// | |
| 442 /// Use this to highlight something successful or otherwise positive. | |
| 443 String green(text) => "$_green$text$_noColor"; | |
| 444 | |
| 445 /// Wraps [text] in the ANSI escape codes to color it magenta when on a | |
| 446 /// platform that supports that. | |
| 447 /// | |
| 448 /// Use this to highlight something risky that the user should be aware of but | |
| 449 /// may intend to do. | |
| 450 String magenta(text) => "$_magenta$text$_noColor"; | |
| 451 | |
| 452 /// Wraps [text] in the ANSI escape codes to color it red when on a platform | |
| 453 /// that supports that. | |
| 454 /// | |
| 455 /// Use this to highlight unequivocal errors, problems, or failures. | |
| 456 String red(text) => "$_red$text$_noColor"; | |
| 457 | |
| 458 /// Wraps [text] in the ANSI escape codes to color it yellow when on a platform | |
| 459 /// that supports that. | |
| 460 /// | |
| 461 /// Use this to highlight warnings, cautions or other things that are bad but | |
| 462 /// do not prevent the user's goal from being reached. | |
| 463 String yellow(text) => "$_yellow$text$_noColor"; | |
| 464 | |
| 465 /// Log function that prints the message to stdout. | |
| 466 void _logToStdout(Entry entry) { | |
| 467 _logToStream(stdout, entry, showLabel: false); | |
| 468 } | |
| 469 | |
| 470 /// Log function that prints the message to stdout with the level name. | |
| 471 void _logToStdoutWithLabel(Entry entry) { | |
| 472 _logToStream(stdout, entry, showLabel: true); | |
| 473 } | |
| 474 | |
| 475 /// Log function that prints the message to stderr. | |
| 476 void _logToStderr(Entry entry) { | |
| 477 _logToStream(stderr, entry, showLabel: false); | |
| 478 } | |
| 479 | |
| 480 /// Log function that prints the message to stderr with the level name. | |
| 481 void _logToStderrWithLabel(Entry entry) { | |
| 482 _logToStream(stderr, entry, showLabel: true); | |
| 483 } | |
| 484 | |
| 485 void _logToStream(IOSink sink, Entry entry, {bool showLabel}) { | |
| 486 if (json.enabled) return; | |
| 487 | |
| 488 _printToStream(sink, entry, showLabel: showLabel); | |
| 489 } | |
| 490 | |
| 491 void _printToStream(IOSink sink, Entry entry, {bool showLabel}) { | |
| 492 _stopProgress(); | |
| 493 | |
| 494 bool firstLine = true; | |
| 495 for (var line in entry.lines) { | |
| 496 if (showLabel) { | |
| 497 if (firstLine) { | |
| 498 sink.write('${entry.level.name}: '); | |
| 499 } else { | |
| 500 sink.write(' | '); | |
| 501 } | |
| 502 } | |
| 503 | |
| 504 sink.writeln(line); | |
| 505 | |
| 506 firstLine = false; | |
| 507 } | |
| 508 } | |
| 509 | |
| 510 /// Namespace-like class for collecting the methods for JSON logging. | |
| 511 class _JsonLogger { | |
| 512 /// Whether logging should use machine-friendly JSON output or human-friendly | |
| 513 /// text. | |
| 514 /// | |
| 515 /// If set to `true`, then no regular logging is printed. Logged messages | |
| 516 /// will still be recorded and displayed if the transcript is printed. | |
| 517 bool enabled = false; | |
| 518 | |
| 519 /// Creates an error JSON object for [error] and prints it if JSON output | |
| 520 /// is enabled. | |
| 521 /// | |
| 522 /// Always prints to stdout. | |
| 523 void error(error, [stackTrace]) { | |
| 524 var errorJson = { | |
| 525 "error": error.toString() | |
| 526 }; | |
| 527 | |
| 528 if (stackTrace == null && error is Error) stackTrace = error.stackTrace; | |
| 529 if (stackTrace != null) { | |
| 530 errorJson["stackTrace"] = new Chain.forTrace(stackTrace).toString(); | |
| 531 } | |
| 532 | |
| 533 // If the error came from a file, include the path. | |
| 534 if (error is SourceSpanException && error.span.sourceUrl != null) { | |
| 535 errorJson["path"] = p.fromUri(error.span.sourceUrl); | |
| 536 } | |
| 537 | |
| 538 if (error is FileException) { | |
| 539 errorJson["path"] = error.path; | |
| 540 } | |
| 541 | |
| 542 this.message(errorJson); | |
| 543 } | |
| 544 | |
| 545 /// Encodes [message] to JSON and prints it if JSON output is enabled. | |
| 546 void message(message) { | |
| 547 if (!enabled) return; | |
| 548 | |
| 549 print(JSON.encode(message)); | |
| 550 } | |
| 551 } | |
| OLD | NEW |