Summary of "Campaign to use real logging in Dart" (via tldr.io)
- Using print() statements for debugging in your libraries means that everyone gets your print() output.
- The Dart SDK has a "logging" package built in (that lets you write into a logging framework), but nothing to output those log messages.
- The "logging_handlers" package adds those missing handlers, letting you output to the console (like print), filesystem (server side), and a webui component.
- Now you (and I) can control the logging output from different libraries by varying the logging level different libraries.
Stop Using print(msg) start using info(msg)
When you use print(), other users of your code have to see all your internal debug logging (I know I'm guilty of this, too).
The logging_handlers package lets you use proper logging in your client-side or server side Dart application.
Why?
When I use your library (or when you use my library), I want to control the amount of logging output from your debug messages (and, I hope, you want to do the same for my debug messages). By using the Dart logging framework, we can both be happy.
There are two parts involved in logging:
- Sending log messages into a logging framework
- Outputting the log messages somewhere (eg, to the stdout, a file, the browser).
Dart's print() sort of covers both of these use cases, and the quick'n'dirty alternative described below also does the same thing. It's not the best way, but at least it means that log messages can be output somewhere other than the console (such as a file).
First, some background about logging
Dart's logging pub package, that forms part of the Dart SDK, covers use-case 1, in other words, it lets you send log messages into a logging framework.
This framework lets you attach handlers to that framework that can listen to the stream of log messages.
This package, logging_handlers provides some default handlers that lets you output messages to a variety of locations, in a variety of formats.
At the moment, you can output a log message as a tab delimited String or a JSONableMap, and you can output a log message to the console similar to print(), to a server-side file, or to a client-side web-ui component (or a mixture).
The quickest (and dirtiest) way to replace print()
This is not the best way, but it's certainly better than print().
- Add
logging_handlers package to pubspec.yaml
import 'package:logging_handlers/logging_handlers_shared.dart';- Use
debug(msg), info(msg), warn(msg), error(msg) as appropriate.
- Somewhere in your initialization code (start of your unit tests,
main() or other initialization code), call startQuickLogging()
For example:
import 'package:logging_handlers/logging_handlers_shared.dart';
main() {
startQuickLogging();
info("Hello World");
}
will output to the console:
2013-05-06 16:42:42.593 [INFO]: Quick'n'Dirty logging is enabled. It's better to do it properly, though.
2013-05-06 16:42:42.604 [INFO]: Hello World
Note: Dart's logging has more fine grained logging levels - the top-level functions above are shorthand for some of these:
FINEST // highly detailed tracing
FINER // fairly detailed tracing
debug(msg) = FINE // tracing information
CONFIG // static configuration messages
info(msg) = INFO // informational messages
warn(msg) = WARNING // potential problems
error(msg) = SEVERE // serious failures
SHOUT // extra debugging loudness
But see below for better ways that allow users of your code more control over what actually gets output, and let you have finer-grained control over logging.
The a slightly better way (but still a bit quick'n'dirty) to replace print()
Let users of your code filter out your specific log messages by giving your log messages a name. The best name is the name of your library. for example:
library my_library;
import 'package:logging_handlers/logging_handlers_shared.dart';
class Foo() {
Foo() {
debug("Foo is created", "my_library"); // calls debug with your library name
}
}
main() {
startQuickLogging();
new Foo();
}
this outputs:
2013-05-06 16:42:42.593 [INFO]: Quick'n'Dirty logging is enabled. It's better to do it properly, though.
2013-05-06 16:42:42.604 my_library [FINE]: Foo is created
When you include your library name in your log messages, other users of your code can filter your log messages out (more on that later).
The best way to implement logging in your libraries
Create a Logger instance in your library, and give it the name of your library:
library my_library;
import 'package:logging_handlers/logging_handlers_shared.dart';
final _logger = new Logger("my_library");
class MyClass {
MyClass() {
_logger.fine("MyClass created");
}
foo() {
_logger.error("Something bad has happened");
}
}
You can have as many loggers as you need, and they can be hierarchical (using a . to separate). For example, you might have a top-level logger, and individual loggers for specific classes:
library my_library;
import 'package:logging_handlers/logging_handlers_shared.dart';
final _libraryLogger = new Logger("my_library"); // top level logger
class MyClass {
// MyClass logger is a child of my_library logger
static final _logger = new Logger("my_library.MyClass");
MyClass() {
MyClass._logger.fine("MyClass created"); // using class logger
}
foo() {
_libraryLogger.error("Something bad has happened"); // using top-level logger
}
}
When you use hierarchical logging, you (and your code's users) can start to take control over what actually gets output, and to where (such as outputting ALL logging for MyClass, but only WARNING, SEVERE and SHOUT logging for the library).
Now that you've seen how to emit log messages into a framework, let's take a look at how to control where those messages go
Controlling log message output
The code in your classes and libraries don't actually run until you pull them into a Dart application (or unit test) via the top-level main() function.
In the main() function, you need to initialize the logging framework with a logging handler. The simplest version of this is the PrintHandler, which outputs log messages to the console in the same way that print() does.
Let's assume that you've implemented logging using "the best way" which contains your logger name.
// the SDK logging framework
import 'package:logging/logging.dart';
// Handlers that are shared between client and server
import 'package:logging_handlers/logging_handlers_shared.dart';
// your library, from above...
import 'my_library';
main() {
Logger.root.onRecord.listen(new PrintHandler()); // default PrintHandler
var myclass = new MyClass(); // from above - outputs log message
}
If you're on the server-side, and you want to log to a file, the logging_handlers package includes a very simple (synchronous) filesystem log file handler: SyncFileLoggingHandler.
// the SDK logging framework
import 'package:logging/logging.dart';
// Handlers that run server-side
import 'package:logging_handlers/server_logging_handlers.dart';
// your library, from above...
import 'my_library';
main() {
Logger.root.onRecord.listen(new SyncFileLoggingHandler("myLogFile.txt"));
var myclass = new MyClass(); // from above - outputs log message
}
And if you're on the client side, there's a handy (and incredibly basic) web component<x-loggerui> to output log messages on screen.
In your Web UI enabled application, your HTML will look something like this:
<html>
<head>
<!-- import the loggerui component -->
<link rel="import" href="package:logging_handlers/src/client/loggerui.html">
</head>
<body>
<!-- other content... -->
<x-loggerui></x-loggerui> <!-- Logger widget -->
<!-- standard app scripts -->
<script type="application/dart" src="test.dart"></script>
<script src="packages/browser/dart.js"></script>
</body>
</html>
And in your app's main() function, you call attachXLoggerUi() like this:
import 'package:logging_handlers/browser_logging_handlers.dart';
main() {
attachXLoggerUi(); // lives in the browser_logging_handlers library
}
The attachXLoggerUi function runs in the next event loop iteration after main (usingTimer.run), so any startup logging won't appear. This is because the web component's themselves aren't available until the next event loop.
Here is a running example:
Attaching multiple handlers
Sometimes, you want to attach multiple handlers. That's fine, because the logging framework uses Streams, so you just need to use asBroadcastStream():
main() {
var loggerStream = Logger.root.onRecord.asBroadcastStream();
// attach the PrintHandler and the File logging handler
loggerStream.listen(new PrintHandler());
loggerStream.listen(new SyncFileLoggingHandler("myLogFile.txt"));
}
Note At present, the implementations of the client and server handlers are fairly basic, but given time (and your help?), they should get greater functionality. Ideas include: Allowing the x-loggerui to filter based on level.
or creating an async version of the server side logger.
Getting more control over the output
Now you have seen what can be output, let's take a look at how you customize that.
Each of the handlers (LoggerUi, SyncFileLoggingHandler and PrintHandler) implement aBaseLoggingHandler interface. These have a LogRecordTransformer instance, that transforms an SDK LogRecord into some other format.
The logging_handlers package contains two transformers that implementLogRecordTransformer: StringTransformer and MapTransformer. All three handlers use a default implementation of a StringTransformer, but you can pass an alternative transformer into the constructor of both the PrintHandler or SyncFileLoggingHandler.
StringTransformer
The StringTransformer lets you control the fields that get output, for example:
main() {
var fileHandler =
new SyncFileLoggingHandler("logfile.txt", transformer: new StringTransformer("%m"));
Logger.root.onRecord.listen(fileHandler); // default
var myclass = new MyClass(); // from above - outputs log message
}
The StringTransformer allows formatting strings to specify the output. %m is just the message without all the other information, and replicates the print command.
The full list of formatting strings is shown below:
%p = Outputs LogRecord.level
%m = Outputs LogRecord.message
%n = Outputs the Logger.name
%t = Outputs the timestamp according to the Date Time Format specified
%s = Outputs the logger sequence
%x = Outputs the exception
%e = Outputs the exception message
The default formatting strings are shown below (with \t for tab separation):
DEFAULT_MESSAGE_FORMAT = "%t\t%n\t[%p]:\t%m";
DEFAULT_EXCEPTION_FORMAT = "\n%e\n%x";
DEFAULT_DATE_TIME_FORMAT = "yyyy.mm.dd HH:mm:ss.SSS Z";
You can customize all of these when you create a logger handler.
Replacing the print() command
Now that you have seen some of the formatting available, let's see how you can actually replace the print() command:
main() {
// simulate existing print command by only outputting the message
Logger.root.onRecord.listen(new PrintHandler(messageFormat:"%m"));
}
Taking control: Logging levels and heirarchical loggers
Let's suppose that you are using my library.
We have your_library and my_library
You don't want to see my logging when you test your library.
How can you control it?
Let's look at some code that outputs logging from your_library but not my_library:
import 'package:my_library/my_library.dart'; // don't want to see logging here
import 'your_library.dart'; // Show logging from this library please :)
import 'package:logging/logging.dart';
import 'package:logging_handlers/logging_handlers_shared.dart';
main() {
hierarchicalLoggingEnabled = true; // set this to true - its part of Logging SDK
// now control the logging.
// Turn off all logging first
Logger.root.level = Level.OFF;
Logger.root.onRecord.listen(new PrintHandler());
// create a logger for your library
// (there will be a single instance for each logger with the same name)
// and set the level to ALL
new Logger("your_library")..level = Level.ALL;
doSomethingInYourLibrary(); // logging is output to console
doSomethingInMyLibrary(); // logging is not be output
}
Now let's use the hierarchy to use different logging for a specific class (assuming that you have a class logger created for your_library.YourClass):
main() {
hierarchicalLoggingEnabled = true; // set this to true - its part of Logging SDK
// now control the logging.
// Turn off all logging first
Logger.root.level = Level.OFF;
Logger.root.onRecord.listen(new PrintHandler());
// create a logger for your library
// (there is only a single instance for each logger with the same name)
// and set the level to ALL
new Logger("your_library")..level = Level.INFO;
new Logger("your_library.YourClass")..level = Level.ALL;
doSomethingInYourLibrary(); // Only INFO logging is output to console
new YourClass(); // All logging output to the console
doSomethingInMyLibrary(); // logging is not be output
}
Quick Reference
Logging best practice
- Add
logging and logging_handlers to pubspec
Import the logging SDK where you want to write log messages
import 'package:logging/logging.dart';
Create a logger (or loggers), and use them
``` final _libraryLogger = new Logger("my_library");
doSomething() { _libraryLogger.info("Something is done") }
class MyClass { final _classLogger = new Logger("my_library.MyClass")
MyClass() { _classLogger.fine("MyClass is constructed"); } } ```
When you use your library / class, and want to output some logging, create an instance of a LoggingHandler and attach it to the root logger
``` import 'package:logging_handlers/logging_handlers_shared.dart'; import 'your_library';
main() { Logger.root.onRecord.listen(new PrintHandler()); } ```
When you want finer control over what get's output, use hierarchical loggin and set levels
``` import 'package:logging_handlers/logging_handlers_shared.dart'; import 'your_library'; import 'package:my_library/my_library.dart';
main() { Logger.root.onRecord.listen(new PrintHandler()); Logger.root.level = Level.OFF; // log nothing by default new Logger("your_library")..level = Level.ALL; // log all in your library
} ```
Server handlers are found here:
import 'package:logging_handlers/server_logging_handlers.dart';
Client logging handlers are found here:
import 'package:logging_handlers/browser_logging_handlers.dart';
Web UI component is here:
<link rel="import" href="package:logging_handlers/src/client/loggerui.html">
...
<x-loggerui></x-loggerui>
...
// and in your script, call:
import 'package:logging/logging.dart';
import 'package:logging_handlers/browser_logging_handlers.dart';
main() {
hierarchicalLoggingEnabled = true;
attachXLoggerUi();
}
Caveats
The Logger framework (as at M4), has a TODO about logging exceptions. At the moment it doesn't. If you want to log exceptions, add the exception text to the log message.
If you find any problems or errors, then please let me know. This was current as at r21823
Recently I read “
In fact, around 40 people were there.
Get the Dartosphere RSS feed