Logging
Write Actionable Log Messages (LG-001)
Log Messages should be actionable so that the person reading the message will know what to do.
// Not good
[...] com.enactor.core.resources.CachingFileResourceResolver - The search roots are empty.
// Good
[...] com.enactor.core.utilities.WebServicesUtil - Unable to load account credentials id 'MESSAGE_SERVICES from connection diagram
- Execute Action:'ReceiveXMLSerializableMessageAction' State:'Loop' Process:'Pos/Status/CheckDeviceInstructions'
Include Relevant Information in Log Messages (LG-002)
Information that can help understand which data is missing/corrupted should be included in the log message. This will facilitate the investigation
Example of information that can be included: User Id, Product Id, Transaction Id
Make sure not to include personal data, passwords, token, or any other credentials, even in DEBUG log messages
// Not good
[...] com.enactor.core.utilities.WebServicesUtil - Unable to load account credentials id
// Good
[...] com.enactor.core.utilities.WebServicesUtil - Unable to load account credentials id 'MESSAGE_SERVICES'
Check Log Files (LG-003)
All log files for all the applications should be checked for errors and warnings. Ideally, there should be none. It is the responsibility of everyone to ensure that the application does not output unnecessary log. Developer should keep an eye on new errors and warnings that appear in their development environment.
As part of writing a new feature, care should be taken not to introduce new errors or warnings in the logs.
Add Debug Log Files to facilitate Support & Maintenance (LG-004)
DEBUG log messages should be added where appropriate to help long term support of the product.
For instance, if an entity could not be loaded (but would normally be expected to be there), it is useful to have a DEBUG log message for that. The rest of the code should still be made safe (e.g. null check)
Use Appropriate Log Levels (LG-005)
Select the correct log level for each message to ensure logs are clear and informative.
As an example, Enactor application will usually attempt to continue whenever it encounters a problem.
-
ERROR example - If the price of a Product could not be found, the operator will be told that the price could not be found and the item will not be sold. In such situation, the logs will contain an ERROR message (with the product id so that it is actionable)
-
WARNING example - If a message translation is missing, the Enactor will use the Message ID in its place and will continue as normal. A WARNING message should however indicate that the message translation is missing. (again, the message Base and message ID should be present in the message).
-
DEBUG example - reserved for debugging and support. A well configured application should have nothing in the log unless DEBUG is turned on. Using Debug message to help understanding the code path that the application follows. For instance, did the application load the credentials with or without a location id.
-
INFORMATION example - message that we want to output to help understand how the application works. This is similar to DEBUG but is a lot less verbose and should not be too technical. For instance, in order to know which menu was used, one can turn on INFORMATION logging on LoadMenuAction action to display the menu key of each menu loaded by the application
// LoadMenuAction
logger.log(Logger.LOG_INFORMATION, "Using '" + menu.getName() + "' menu (" + menu.getKey() + ")"); -
VITAL_INFORMATION example - message that we always want to output but are for information only should be done using VITAL_INFORMATION. This should be rare and reserved in low level initialisation, such as when we create the db schema.
// SchemaManager
logger.log(Logger.LOG_VITAL_INFORMATION, mappedSchemaEntityName + " - creating schema (" + mapping.getVersion()+ ")");
In the example below, the system has detected a slow process but that has not resulted in an error (i.e. the function executed correctly albeit slower than expected). It is therefore a WARNING message
2022-10-11 10:54:21.492 [AWT-EventQueue-0] WARN com.enactor.coreUI.processes.ProcessPerformanceLogger - Warning! Execute of Process 'Pos/Transaction/SendTransaction'
took 171 ms at 'SendTransaction' in 'Pos/SystemEvent/LogPosSystemEvent' :Execute Action:'EndProcessSuccess' State:'SendViaProcessingQueue' Process:'Pos/Transaction/SendTransaction'
Avoid Repeating Logs (LG-006)
Prevent logs from being continuously filled with repeated messages. For instance, if a client repeatedly tries to connect to a server and logs an error each time, it can flood the log files. Implement strategies like fixed retry counts or exponential backoff retries to manage repeated attempts and logging using Logger.getRestrictedVolumeLogger.
Exception should not be blindly ignored (LG-007)
In general, exception should result in a log message. This can be a DEBUG log level. Alternatively, the exception should generally be re-thrown and not simply swallowed.