Colorized logging for Flutter development with VS Code

#flutter #vscode #dart

At a certain point in a new development project, logging becomes less of a nice to have and more of a necessity. I recently hit that breaking point with a Flutter project I've been working on. There were things happening in the background, such as calling REST APIs, and I had no idea whether they were working correctly or not. I didn't want to add temporary print() statements but needed the basic visibility that logging provides.

After picking a good time to add logging, I did a little research to see what was available. The requirements were pretty straightforward:

Simplicity - easy to set up and add events
Support for basic fields in the log output
- time - timestamp of when the event occurred
- message - string describing what happened
- level - indication of whether it was informational, a warning, an error, etc.
- location - where in the codebase did the event come from
Ability to turn down verbosity overall, but turn it up in desired areas
Colorized log output to quickly identify whether something went wrong and what it was

There may other requirements down the road, but this would be enough to get things started.

Logging Setup

Fortunately, the Dart team provided the logging package that looked like it would have what I wanted. The next few steps detail setting that up.

First, add the package to your pubspec.yaml file:



dependencies:
  logging: ^0.11.4

Next, create an initialization function, which I chose to put in lib/infra/logger.dart:



import 'package:logging/logging.dart';

void initRootLogger() {
  Logger.root.level = Level.ALL; // defaults to Level.INFO
  Logger.root.onRecord.listen((record) {
    print(
        '${record.time}: ${record.loggerName}: ${record.level.name}:  ${record.message}');
  });
}

void exampleLogs(Logger logger) {
  print('example print');
  logger.finest('example finest log entry');
  logger.finer('example finer log entry');
  logger.fine('example fine log entry');
  logger.info('example info log entry');
  logger.warning('example warning log entry');
  logger.severe('example severe log entry');
  logger.shout('example shout log entry');
}

As you can see above, I also created a function to generate some example logging output at the different levels that were supported.

This new function to initialize the root logger needs to be called from the 'main()' function so logging will be immediately available and configured:



// needed to use the initRootLogger function
import '../infra/logger.dart';

void main() {
  // initialize the root logger prior to running the app
  initRootLogger();
  runApp(Founce());
}

Lastly, I added code to an existing class so it could do some logging:



// add this import in every file where logging is desirable
import 'package:logging/logging.dart';
// only needed for exampleLogs
import '../infra/logger.dart';

class SiteInfoService with ChangeNotifier {
  static final _log = Logger('SiteInfoService');
  // other class variables ...

  void _getSiteUpdates() {
    // call the function to generate the examples
    exampleLogs(_log);
    // make a logging call, add similar where desired
    _log.info('retrieving site updates');
    // get the site updates ...
  }
}

That was pretty quick and easy and this is how it looks in the debug console of Visual Studio Code, which is my IDE of choice for Flutter development.

Not bad, it's got the timestamp, class that the logs came from, level and the message. It's just all very... blue. There's no differentiation between regular print messages, logging output and messages from Flutter or VS Code. I was happy with the simplicity of the config and logging calls, but if I'm going to be using this for the foreseeable future then some colorization would be really useful.

Adding Colorization

Some initial searching indicated mostly that people had tried adding some colors to the debug console output without success. The main issue appeared to be that ANSI color codes were being ignored when the print() output made it to the debug console on VS Code.

On the verge of giving up, I noticed that there is an alternate method of logging described by Google. Essentially, it uses calls to developer.log() to output the messages instead of print(). An initial try indicated that ANSI color codes could be used to have colorized output on the VS Code debug console. Here's how it looks now:

Things I like about how it turned out:

The fine, finer and finest logging blends into the background.
Info events are a little more visible and it gets louder from there.
The print statements and anything else from Flutter or VS Code shows up in blue, making it very easy to distinguish.

Something I wish could be a little better:

Since the time is always the same length, I would have preferred that it come first. Unfortunately, developer.log() puts the logger name first. This means that different length class names will shift the rest of the message and would have made it a little messier visually. Padding the logger name helped, but the extra white space isn't ideal.

To add colorized logging to your code, the main difference from the above setup is a different initRootLogger() function:



import 'package:logging/logging.dart';
import 'package:flutter/foundation.dart';
import 'dart:developer' as developer;

void initRootLogger() {
  // only enable logging for debug mode
  if (kDebugMode) {
    Logger.root.level = Level.ALL;
  } else {
    Logger.root.level = Level.OFF;
  }
  hierarchicalLoggingEnabled = true;

  // specify the levels for lower level loggers, if desired
  // Logger('SiteInfoService').level = Level.ALL;

  Logger.root.onRecord.listen((record) {
    if (!kDebugMode) {
      return;
    }

    var start = '\x1b[90m';
    const end = '\x1b[0m';
    const white = '\x1b[37m';

    switch (record.level.name) {
      case 'INFO':
        start = '\x1b[37m';
        break;
      case 'WARNING':
        start = '\x1b[93m';
        break;
      case 'SEVERE':
        start = '\x1b[103m\x1b[31m';
        break;
      case 'SHOUT':
        start = '\x1b[41m\x1b[93m';
        break;
    }

    final message =
        '$white${record.time}:$end$start${record.level.name}: ${record.message}$end';
    developer.log(
      message,
      name: record.loggerName.padRight(25),
      level: record.level.value,
      time: record.time,
    );
  });
}

Of course, you can customize the colors to your liking by selecting different ANSI color codes. A couple other notes about this new initialization code:

The dart:developer package is only available in debug mode. A different mechanism will be needed if logging in a release image is desired.
It is possible to set the logging level of an individual named logger. When adding logging to a class, I created a named logger for it with the class name as the logger name (e.g. static final _log = Logger('SiteInfoService');). This allows control over the logging level for each class during initialization (e.g. Logger('SiteInfoService').level = Level.ALL; in initRootLogger()). For debugging a specific area, set the root logger level to something high like Level.WARNING and then change the class loggers you're debugging to a verbose level like Level.ALL

Happy coding and many thanks to everyone contributing to Dart, Flutter and all the other great open source projects!