Getting to know Winston

- [Michael] Hey there, welcome back to Mastering Express Web Application Development. Last time, we looked at NConfig, and how we can make things that were previously hard coded magic numbers, controllable at run time. Today, we'll be looking at Winston. Winston is a multi-transport logging library for node.js. We'll think about why we need logs and then learn how to instrument our application with Winston and how to control what gets logged in various different environments.

There are lots of other options for logging, such as Bunyan, and the built-in console.log. But after trying lots of different projects, Winston feels like the most powerful to me. We should probably start by understanding why we need logs in our application. Logs are a fundamental part of our application development. Generally, they used to help us diagnose what happened when something goes wrong within our application. One very useful application of logs is when there is a problem in production, but you do not want to expose errors to the users.

Logs allow you to get the debug information without giving anything away to the user. Why stop there, though? Why shouldn't we log everything that happens within our application? Having an application log makes it really easy to work out what's going on inside your application at any point in time. As always, we need to install the package from npm. In this case, we need to use the npm install winston. We pass --save, to save it to our package.js own file.

Once it's installed, we can start using Winston. Let's start by editing app.js and requiring Winston. As well as requiring Winston, we are going to add a log message to make sure that it works. I'm just going to go to the bottom of our NConfig definitions. I'll write a message that says we've initialized nconf. Let's start our application to make sure that worked. There we have it. Info, initialized nconf.

As well as logging simple strings, nconf has support for logging complex objects. I'm going to add another log message here, which logs our http config from nconf. So if I restart our application, we can see that at the info level, our HTTP Config, is being logged out, and we can see that our application is running on port 8002. So let's delete the command line flag and the environment variable.

I'll make sure that our application starts, which it does. That means in the future, when we want bin/www, our application will be running on port 8000, just like we expect. So, Winston info, what does that actually mean? Info is a severity level, saying that this is an informational message. Winston ships with a default set of log levels. In order of severity, default levels are silly, debug, verbose, info, warn, and error.

This means that an error is more important than a warning, and a warning is more important than informational messages. When you start your application, you can tell Winston which levels you want to log, meaning that you can go crazy with debug logs in development, but only show warnings and errors in production. That way, you won't end up with log files that are hundreds of megabytes and even gigabytes big. By default, Winston logs to the console. This is great for development, but maybe you want to log errors to a file for review later, whilst still showing everything in the console.

Winston makes this easy. Let's do that now. So, edit app.js and after we've required Winston, we want to customize it a little bit. We say, Winston add a new file transport. And we're going to log error.log. And we only want to log anything that has a severity of error or above. Now you show that in action. I'm going to add a code to Winston error saying that something went wrong.

I'm going to start our application. As we can see, the error is logged and the info is logged. However, if I show the contents of error log, only the error message is in there. The informational messages aren't stored. This is because we said the minimum level to log is error. Let's remove that now. As well as logging, Winston also provides a simple profiling mechanism. Winston profile takes an identifier as a first parameter.

The first time it's called, it starts timer. And when it calls again with the same identifier, it stops the timer, logging how much time it lapsed between those two calls. In this case, I'm going to give a timer to the second, and when I run my application, there we are. We see at the info level, the identifier test had the duration of 1002 milliseconds. That's about the second that we expected.

Again, let's remove that as we have no use for it. By default, Winston only comes with two transports, console and file. Fortunately there's a large ecosystem of third party loggers available, including Loggly, Reac, MongoDB, SimpleDB, email, Graylog2, Papertrail, and Cassandra. To use them, just install them by npm and require them in your app.

I've decided that I want to get all of the errors emailed to me, so I'm going to install Winston mail. Next, back to app.js. Here, I require Winston now. I don't assign it to anything. This is because Winston transports generally add themselves to Winston.transports. So, just like before, I make a call to Winston add.

This time, with Winston transports mail as the third parameter. As the second parameter, there's a list of options which are available on Winston mail readme on GitHub. The first is who do you want to send the email to. The second is the username for the smtp server and the third is the password. There are lots of other options, but they come with smart defaults. Finally, we need to set the level that this transport should be activated on.

As I only want errors emailed to me, I've put error in here. I should add that using npm to install the transports only installs the code required to send the logs to each destination. For example, if you use MongoDB transport, you have to install MongoDB first before it will work. Yet again, I'm not going to do this whilst developing the app, so I'm just going to clean things up a little bit. I've just removed Winston mail from my application.

By default, Winston uses the logging levels defined by the npm, which we saw earlier. If the built-in logging levels aren't enough for you, Winston makes it very easy to create your own. All you need to do is define a list of levels and any colors associated with them. Then, when you create a logger, set it to use your custom logging levels. Any levels you create, will automatically be created as functions on the logger, so in this case we can call customLeverLogger.bar.

Something that the Winston documentation on custom levels fails to mention is that you have to give a new logger a transport, otherwise it doesn't know where to send the messages. So let's do that. You can add multiple transports to a new logger instance, but here we've just said, send it to the console. And, as always, when adding a transport, you have to tell it what level to activate on. In this case, I've chosen foo, our lowest custom level.

Let's see that in action. Start our application, and there it is, the first message, bar. This is an example. Again, this isn't something that we are going to be using much, so I'm just going to go and remove it from our application. That brings us to the end of our Winston tour. There's still one more thing to do. When we add the file transport, we specify that we should log everything error and above. Wouldn't it be great if that was configurable? Let's make that happen.

So we start by moving the Winston add call to below nconf definition. Next, we change the hard coded error string to be a call to nconfig.get, and we'll say, get the value in logger file level. Finally, we need to add logger file level to our nconf defaults. Now, if we run things, it should work just as it did before, where everything error and above is logged to a file, but everything else comes to the console.

Conclusion, Winston is an awesome library for keeping track of what's going on inside your application. You can use it as little or as much as you like. You can use it just like console log, if you want to, but you can do much, much more. Next time, we'll actually start to build our application. We'll be installing Nunjucks, my templating framework of choice, and configuring it to work with Express.