console.log
console.log
no-console
In this article, we will explore various scenarios where you need to print information; What is the difference between console.log and console.error in Node.js? And how to log in the library without messing with the user console.
console.log(`Let's go! `);
Copy the codeFirst theory: The important details of Node.js
If you can use console.log or console.error in a browser or node.js, there is one important thing to remember when using Node.js. When writing the following code using Node.js in a file named index.js:
console.log('Hello there');
console.error('Bye bye');
Copy the codeExecute it on the terminal using Node index.js, and you’ll see them printed side by side:
However, although the two look the same, they are actually treated differently by the system. If you look at the Node.js documentation for console, you can see that console.log is output to stdout and console.error is output to stderr.
Each process has three available streams by default: stdin, stdout, and stderr. The STDIN stream handles input coming into the program. For example, button pressing or redirecting output (we’ll get to that later). The STdout stream is used for the output of the application. Finally, stderr is used for error messages. If you want to know why stderr exists and when to use it, see this article.
In short, we can use the redirect (>) and a pipe (|) operator to the application of error separation and diagnostic information display. The > operator allows us to redirect the output of stdout to a file, while 2> allows us to redirect the output of stderr to a file. For example, this command imports “Hello there” into a file named hello.log and “Bye Bye” into a file named error.log.
node index.js > hello.log 2> error.log
Copy the code
When do we need a log?
Now that we’ve looked at some of the underlying technical aspects of logging, let’s discuss the scenarios in which logging might be required. Typically these scenarios include the following categories:
- Quickly debug exceptions during development
- Browser-based logging for analysis or diagnostics
- Log the service application to record incoming requests and any failures that may occur
- Optional debug logs for the library to assist users in troubleshooting problems
- You can print progress, confirmation, or errors on the CLI
We’ll skip the first two scenarios and focus on the next three related to Node.js.
Service Application Logs
There can be many reasons for logging on the server. For example, logging incoming requests can be used to do statistics on information such as how many 404 requests the User encountered, what those requests might be, or what user-agent is being used. We also want to know when something went wrong and why.
Create a new project directory if you want to try out the rest of this article. Create index.js in the project directory as a program run entry for writing code. Run the following code to initialize the project and install Express:
npm init -y
npm install express
Copy the codeLet’s set up a server with console.log middleware. Put the following into the index.js file:
const express = require('express');
const PORT = process.env.PORT || 3000;
const app = express();
app.use((req, res, next) = > {
console.log('%O', req);
next();
});
app.get('/', (req, res) => {
res.send('Hello World');
});
app.listen(PORT, () => {
console.log('Server running on port %d', PORT);
});
Copy the codeWe use console.log(‘$0’,req) to log the entire object. The console.log base supports %O placeholders using the util.format method. Details can be found in the official Node.js documentation.
When executing Node index.js to execute the server and visit http://localhost:3000, you’ll notice that it will print out a lot of information we don’t really need.
Even if we changed it to console.log(‘%s’, req) and didn’t print the whole object, we wouldn’t get much useful information.
We can write our own log function that only outputs what we care about. But before we do that, let’s talk about what we generally care about. While too much information can distract us, we actually need enough information. Such as:
- Time stamp – Knows when something happened
- Computer/server name – if you are running a distributed system
- Process ID – If you are running multiple node processes using something like PM2
- Message – An actual message that contains some content
- Stack trace – used to record error scenarios
- Some additional variables/information
In addition, now that we know that everything is going into the STdout and Stderr streams, we can leverage them to implement different levels of logging and the ability to configure and filter logs against them.
We can do all of this by accessing various parts of the process and writing a bunch of JavaScript, but the best thing about Node.js is that it has an NPM ecosystem, and there are libraries already available. Such as:
- pino
- winston
- roarr
- Bunyan (Note: this hasn’t been updated in two years)
I personally like Pino because it’s fast and ecological. Let’s look at how pino can help us with our logging. The cool thing is that there is already an Express-Pino-Logger package that we can use to log requests.
Install pinO and Express-Pino-Logger:
npm install pino express-pino-logger
Copy the codeThen update the index.js file, using the logger and middleware:
const express = require('express');
const pino = require('pino');
const expressPino = require('express-pino-logger');
const logger = pino({ level: process.env.LOG_LEVEL || 'info' });
const expressLogger = expressPino({ logger });
const PORT = process.env.PORT || 3000;
const app = express();
app.use(expressLogger);
app.get('/', (req, res) => {
logger.debug('Calling res.send');
res.send('Hello World');
});
app.listen(PORT, () => {
logger.info('Server running on port %d', PORT);
});
Copy the codeIn this code snippet, we create a logger instance of PINo and pass it to express-Pino-Logger to create a new logger middleware for the app.use call. In addition, we replaced console.log with logger.info at service startup, and added an additional logger.debug to the route to display different levels of logs.
Start the server by running Node index.js again. You’ll see a very different output, one JSON per line. Visit http://localhost:3000 again and you will see that a new line of JSON has been added.
If you examine the JSON, you will see that it contains all the information mentioned earlier, such as timestamps. You may also notice that our logger.debug statement is not printed. This is because we used the default log level. When creating a Logger instance, we change the log level by setting process.env.log_level, which defaults to INFO. By running LOG_LEVEL=debug node index.js, we can adjust the log level to display logs of the DEBUG type.
Before we do that, let’s discuss the fact that the current output is actually very unreadable. Yet this is deliberate. Pino follows a principle of higher performance. We can also through the pipe (|) move the all process of log into a separate process, used to improve its readability or a cloud of data uploaded to the server. This process is called transports. Check the documentation on TranSports to see why the error in PINO was not written to stderr.
Let’s use the tool Pino-Pretty to see a more readable version of the log. Run the following command on the terminal:
npm install --save-dev pino-pretty
LOG_LEVEL=debug node index.js | ./node_modules/.bin/pino-pretty
Copy the codeNow, using the | operator, all logging to transmit through pipes to pino – pretty, your output should be clear, contains key information and being shaded. Visit http://localhost:3000 again and you should also see debug level messages.
There are a number of transport tools available to beautify or transform logs. You can even make it emoticons with pino-Colada. These will be very useful for your local development. After running the server in production, you may want to import the logs into another transport, write the logs to disk using > so they can be processed later, or process them using a command like tee.
The official documentation also covers archiving, filtering, and writing logs to different files.
Your library log
Now that we know how to log efficiently for server applications, why not use the same technique for the libraries we write?
The problem is that we want to print out the library for debugging without confusing the user’s application. Users should be able to enable logging if they need to debug something. Your library should be silent by default, leaving it up to the user to decide whether to print logs.
Express is a good example. The bottom layer of Express does a lot of things, and you might want to take a look at the bottom layer when debugging your application. If we look at the Express documentation, we’ll notice that to start the related log, we just need to prefix the command with DEBUG= Express :*:
DEBUG=express:* node index.js
Copy the codeRun this command with an existing application and you’ll see a lot of additional output that will help you debug the problem.
If debug logging is not enabled, you will not see this. This is done through a package called DEBUG. It allows us to write messages under the specified “namespace” that will be printed if the consumer of the library contains a matching namespace or wildcard in the debug environment variable.
To use the Debug library, first install it:
npm install debug
Copy the codeLet’s try it out by creating a new file that emulates our library random-id.js and places the following code in it:
const debug = require('debug');
const log = debug('mylib:randomid');
log('Library loaded');
function getRandomId() {
log('Computing random ID');
const outcome = Math.random()
.toString(36)
.substr(2);
log('Random ID is "%s"', outcome);
return outcome;
}
module.exports = { getRandomId };
Copy the codeThe above code creates a new debug log instance with a namespace of mylib: RandomId that prints two messages. Let’s use it in index.js in the previous chapter:
const express = require('express');
const pino = require('pino');
const expressPino = require('express-pino-logger');
const randomId = require('./random-id');
const logger = pino({ level: process.env.LOG_LEVEL || 'info' });
const expressLogger = expressPino({ logger });
const PORT = process.env.PORT || 3000;
const app = express();
app.use(expressLogger);
app.get('/', (req, res) => {
logger.debug('Calling res.send');
const id = randomId.getRandomId();
res.send(`Hello World [${id}] `);
});
app.listen(PORT, () => {
logger.info('Server running on port %d', PORT);
});
Copy the codeRe-run the server, but this time with DEBUG=mylib:randomid node index.js, which will print the DEBUG log for our “library”.
Interestingly, if your library users want to put this debugging information into their PINO logs, they can use the Pino-Debug library provided by the PinO team to properly format these logs.
Install the library using the following method:
npm install pino-debug
Copy the codeBefore you can use Debug for the first time, you need to initialize pino-Debug. The easiest way to do this is to use the Node.js -r or — require flag to import modules before starting the script. Run the server again with the following command (assuming pino-Colada is installed):
DEBUG=mylib:randomid node -r pino-debug index.js | ./node_modules/.bin/pino-colada
Copy the codeYou will now see that the library debug log is in the same format as the application log.
Output from the CLI
The final case we’ll discuss in this article is the special logging case of CLIs rather than libraries. My rule is to separate logical logs from the “logs” output by the CLI. For any logical log, you should use a library like DEBUG. This way, you or someone else can reuse logic without being tied to a cli-specific use case.
When your Node.js application is CLI built, you may want to make it look prettier by adding colors, markers, or formatting the content in a particular visually appealing way. However, there are a few scenarios you should keep in mind when using CLI builds.
One scenario is that your CLI might be used in the context of a continuous integration (CI) system, so you might want to remove colors or any fancy decorative output. Some CI systems set an environment flag called CI. If you want to check if you are in CI more securely, you can use a package like IS-CI, which already supports many CI systems.
Some libraries, such as Chalk, already detect CI environments for you and remove colors for you. Let’s take a look at what it looks like using it.
Use NPM to install Chalk and create a file called clip.js. Put in the following code:
const chalk = require('chalk');
console.log('%s Hi there',chalk.cyan('INFO'));
Copy the codeNow, if you run the script using Node Clip.js, you’ll see colored output.
But if you run it with CI=true node clip.js, you’ll see that the color is suppressed:
Another scenario to keep in mind is if your STdout is running in terminal mode, indicating that content is written to the terminal. If that’s the case, we can use something like Boxen to display all the nice output. If not, the output is likely to be redirected to a file or pipe somewhere.
You can check whether stdin, stdout, or stderr are in terminal mode by checking the isTTY property on the corresponding stream, for example: process.stdout.istty. TTY stands for “teletypewriter,” in this case a terminal.
These three streams may have different values depending on how the Node.js process is started. You can learn more about this in the “Process I/O” section of the Node.js documentation.
Let’s look at the value of process.stdout. IsTTY varies from case to case. Update your cli.js file to check it:
const chalk = require('chalk');
console.log (process.stdout.isTTY);
console.log('%s Hi there'The chalk. Cyan ('INFO'));
Copy the codeNow run Node Clip.js in your terminal and you’ll see true followed by our color message.
Then run the same thing, but redirect the output to a file and check the contents after running:
node clip .js > output.log
cat output.log
Copy the codeYou’ll see that this time it prints undefined, followed by a solid-colored message, because stdout’s redirection turns off terminal mode for STdout. Chalk uses support-color to check whether TTY is supported on the corresponding stream.
Tools like Chalk already handle this scenario for you. However, when developing the CLI, you should always be aware that the CLI might run in CI mode or redirect output. It can also help you get further into the CLI experience. For example, you can arrange data in a terminal in a nice way, and if isTTY is not defined, switch to something easier to parse.
conclusion
It’s pretty quick to get started with JavaScript and log your first line of code using console.log, but you should think more about logging when you put your code into production. This article merely introduces the various approaches and available logging solutions. But it doesn’t contain everything you need to know. I suggest you look at some of the open source projects that interest you most to see how they address logging issues and what tools they use. Now log all the information instead of just printing the log 😉.
A Guide to Node.js Logging