debugging.md

Debugging

Logging

Having more information sounds like a good thing, but when it comes to logging, it's very easy for a stream of useful information to grow into a flood. This is especially true of Liferay DXP, which has an enormous array of functionality built by many teams. If we log too much, then finding relevant information within the bulk becomes difficult.

Another problem with extensive logging is that it can easily be perceived as "console spew", and that reflects badly on the quality of the product. Customers may not have the necessary context to distinguish messages that indicate real problems from ones which merely seek to helpfully inform. Logging may actually scare or alarm people more than it helps them, especially when you consider the population of users — often customers of our customers — who know enough to open a browser console but who know little or nothing about the underlying system.

So, this leads us to our overall philosophy:

Log as little as possible. Recover gracefully (and preferably silently) from errors. When there are problems that can't be resolved automatically, design user experiences that permit recovery (for example, that allow users to retry operations).

On the use of console.log

console.log may be used as a temporary debugging aid but never committed to the repo, so we use the no-console rule (via eslint-config-liferay) to prevent accidents. console.error and console.warn may be used sparingly to communicate actual problems, but in keeping with our philosophy, always prefer to implement graceful recovery and user experiences that are designed with resilience in mind. The section on NODE_ENV=development below describes one way in which you can avoid the "console spew" problem but still log useful information in a development context while keeping production environments pristine.

Logging and the JS loader

The loader in Liferay DXP is a great example of how useful information can can "grow into a flood", but fortunately, you have full control over how much information it outputs. By default and in normal operation, it won't log anything, but if you ever need to troubleshoot a loading issue you can turn on "Explain Module Resolutions" in the DXP Control Panel, as well as set the log level ("Warn" is a reasonable starting point). To do this, visit the Control Panel » Configuration » System Settings » Infrastructure » JavaScript Loader:

Use of NODE_ENV=development

When we build with NODE_ENV=development we can create sections of code that will only run in development environments. In liferay-npm-bundler, we use babel-plugin-transform-node-env-inline to turn process.env.NODE_ENV === 'development' checks into simple true/false booleans. Thanks to our use of minify-dead-code-elimination Babel plug-in, those checks get completely stripped out in production builds, but remain intact in development environments (see "Environment" for a description of how to set NODE_ENV in Liferay DXP).

As an example of how to log useful information only in development, consider this pull request, which logs a deprecation warning only in development, and only on the first call to a function:

let didEmitDeprecationWarning = false;

export function openSimpleInputModal(data) {
	if (process.env.NODE_ENV === 'development' && !didEmitDeprecationWarning) {
		console.warn(
			'The named "openSimpleInput" export is deprecated: use the default export instead'
		);

		didEmitDeprecationWarning = true;
	}

	return openSimpleInputModalImplementation.call(null, data);
}

If we build in a development environment (using env NODE_ENV=development yarn build, or having done the set-up described in "Environment"), we can inspect the "build/" directory and find that it produced the following code; note how the environment check gets transformed into if (true), which allows the debug code to run:

var didEmitDeprecationWarning = false;

function openSimpleInputModal(data) {
	if (true && !didEmitDeprecationWarning) {
		console.warn(
			'The named "openSimpleInput" export is deprecated: use the default export instead'
		);
		didEmitDeprecationWarning = true;
	}

	return openSimpleInputModalImplementation.call(null, data);
}

In contrast, if we inspect the result in "build/" after doing a production build (ie. using env NODE_ENV=production yarn build), we see that the NODE_ENV check (this time, transformed into if (false) and therefore making our debug code unreachable) got completely stripped out, along with all of the code inside the if:

var didEmitDeprecationWarning = false;

function openSimpleInputModal(data) {
	return openSimpleInputModalImplementation.call(null, data);
}