Difference between revisions of "Logging"

From FMR Knowledge Base
Jump to navigation Jump to search
(Logback Configuration)
(Database Logging)
Line 115: Line 115:
 
         Purpose: Logs information about the Host Manager application.
 
         Purpose: Logs information about the Host Manager application.
 
         Contents: Records deployment and undeployment activities performed through the Host Manager.
 
         Contents: Records deployment and undeployment activities performed through the Host Manager.
 +
 +
=Types of logs in Log File=
 +
 +
Sample log entry:
 +
  2024-01-30 13:34:41.123 INFO main com.example.MyClass - This is a log message
 +
 +
Every log entry consists of the following parts:
 +
# Timestamp when error occurred (eg. 2024-01-30 13:34:41.123)
 +
# Log level  (eg. INFO)
 +
# Thread on which log was produced (eg. main)
 +
# Class that produced the log (eg.  com.example.MyClass)
 +
# Content of the log (eg. This is a log message)
 +
 +
There are multiple types of logs stored in FusionRegistry.log file. Some are more helpful for the end user than others.
 +
 +
==System Information Logs==
 +
Those log entries inform about the state of the system, services being started etc. They are generally not very helpful for end users. Examples:
 +
 +
  2024-01-25 13:49:24.187 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.utils.spring.ApplicationStarterImpl - Starting class io.sdmx.core.dao.base.PersistableMaintainableDao
 +
 +
  2024-01-25 13:49:24.137 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.core.fmr.manager.settings.RegistryPropertiesFileManagerImpl - Set up Email Server Settings
 +
 +
  2024-01-25 13:49:24.115 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.fusion.audit.manager.log.LogManagerImpl - Max Age for Transactional Log Events set to -1 hours
 +
 +
==Error/Warn Information Logs==
 +
If any issues were encountered, please attach logs to your report. Error log entities usually contain stack trace which is helpful for the development team to find the problem in code. Examples:
 +
 +
  2024-01-29 11:05:12.475 ERROR Thread-457 io.sdmx.api.exception.SdmxException - Can not delete mandatory attribute UNIT_MULT
 +
  io.sdmx.api.exception.SdmxException: Can not delete mandatory attribute UNIT_MULT
 +
at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.validateAttributes(ImportPreProcessorEngine.java:298)
 +
at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.validate(ImportPreProcessorEngine.java:253)
 +
at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.run(ImportPreProcessorEngine.java:99)
 +
at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.lambda$new$0(ImportPreProcessorEngine.java:75)
 +
at io.sdmx.fusion.audit.manager.event.AuditEventManager.lambda$startNewThread$7(AuditEventManager.java:308)
 +
        ...
 +
 +
  2024-01-29 13:47:38.233 ERROR http-nio-8080-exec-5 io.sdmx.api.exception.SdmxException - unauthorised
 +
  io.sdmx.api.exception.SdmxUnauthorisedException: unauthorised
 +
at io.sdmx.api.security.ISecurityAdminAuthorisationManager.authorise(ISecurityAdminAuthorisationManager.java:33)
 +
at io.sdmx.api.security.ISecurityAdminAuthorisationManager.authorise(ISecurityAdminAuthorisationManager.java:45)
 +
at com.metadatatechnology.fusion.security.manager.settings.AbstractFusionSecurityRulesManager.checkAuth(AbstractFusionSecurityRulesManager.java:138)
 +
at com.metadatatechnology.fusion.security.manager.settings.AbstractFusionSecurityRulesManager.saveRule(AbstractFusionSecurityRulesManager.java:87)
 +
at com.metadatatechnology.fusion.security.service.GenericFusionSecurityRuleServiceActivator.saveRule(GenericFusionSecurityRuleServiceActivator.java:39)
 +
        ...
 +
 +
 +
 +
 +
  
 
=Database Logging=
 
=Database Logging=

Revision as of 08:05, 1 February 2024

The Fusion Metadata Registry logs information regarding the requests made to it and the work that it is performing. These logs can be long and complicated, but this document aims to explain the logging process.

Logging information is stored in the filesystem as well as in database tables. The files on your system are possibly more transient so unless you take action these will likely be replaced with more recent log information. This is to prevent the size of the log files consuming all of your disk space.


File-based logging

During operation the FMR writes information to its logs. The level of logging is controlled by a system setting in the FMR which directly relates to the logging tool that the FMR uses, which is called Logback. The files generated are also affected by the Java Web-Application Server you are running (for example Apache Tomcat). For the rest of this section, only the scenario when running on Tomcat will be detailed.

Since log files will naturally grow larger over time, if allowed to grow indefinitely, their size would become a problem consuming all the available disk space. This is addressed using rolling file appenders, which automatically “roll” or archive the current log file, and resume logging in a new file when certain predefined conditions occur.

Logback

The logging is controlled by a file called "logback.xml" which is located in the WEB-INF\classes directory under the installed FusionRegistry web application. For example this could be: C:\tomcats\apache-tomcat-9.0.58\webapps\FusionRegistry\WEB-INF\classes

Configuration can be performed by modifying this file. There are different levels of logging:

TRACE: This is for extremely detailed and potentially high volume logs that you don’t typically want enabled even during normal development.
DEBUG: Helpful in tracking the flow through the system and isolating issues, especially during the development and QA phases.
INFO: Used for system lifecycle events (system start, stop) and significant boundary events (e.g., database calls, remote API calls). Typical business exceptions can go here.
WARN: An unexpected technical or business event happened, customers may be affected, but probably no immediate human intervention is required.
ERROR: The system is in distress, customers are probably being affected (or will soon be) and the fix probably requires human intervention.
OFF: This level is intended to turn off logging.

It is not recommended to switch to TRACE or DEBUG level unless specifically requested to by the development team, since the amount of logging produced can be excessive and can cause performance issues.

LoggingLevels.png

Logback Configuration

The logging is controlled by a file called "logback.xml" which is located in the WEB-INF\classes directory under the installed FusionRegistry web application. The file consists of multiple options that can be configured by the user. Some of the more useful parts of this file are:

 Line 2: <configuration scan="true" scanPeriod="30 seconds">

This configuration tells Logback to automatically check for changes in the configuration file every 30 seconds, and if any changes are detected, Logback will reload the configuration.

 Line 8: <appender name="fileout" class="ch.qos.logback.core.rolling.RollingFileAppender">

Start of file appender, responsible for writing logs to the file

 Line 9: <file>${catalina.base:-./temp}/logs/FusionRegistry.log</file>

This line tells Logback the directory and filename to store Registry information into. The default is "FusionRegistry.log"

 Line 10: <encoder> <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %p %t %c - %m%n</pattern> </encoder>

Encoder is responsible for formatting log messages. Current configuration tells logback to format logs like the following:

 2024-01-30 13:34:41.123 INFO main com.example.MyClass - This is a log message
 Line 13: 
 <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
   <maxIndex>4</maxIndex>
   <FileNamePattern>${catalina.base:-./temp}/logs/FusionRegistry.log.%i
   </FileNamePattern>
 </rollingPolicy>

Rolling policy is responsible for creating multiple log files with archived logs. Current configuration tells logback to create up to 4 files named FusionRegistry.log.1 FusionRegistry.log.2 and so on. When a new log file is created (due to a rollover event), the oldest file (if the maximum of 4 is reached) will be deleted, and the other files will be renamed to increment their index.


 Line 18: 
 <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
   <MaxFileSize>10024KB</MaxFileSize>
 </triggeringPolicy>

Triggering policy is responsible for defining when the file will rollover. In current configuration it is around 10MBs. Log file rollover and removal of old logs is necessary to prevent logs consuming all the available disk space.


The next appender tells logback to create additional file FusionRegistryWarnings.log and store there log messages with levels WARN and ERROR, all other configurations align with the first appender

 Line 49:  
 <logger name="com.metadatatechnology" level="INFO" additivity="false">
   <appender-ref ref="fileout" />
   <appender-ref ref="STDOUT" />
   <appender-ref ref="fusionaudit" />
   <appender-ref ref="warnout" />
 </logger>

Logger provides an option to select what is the minimal level of logging and which appenders to use for specified package and all its subpackages. In this case it tells to set minimal level of logging to INFO, and use all 4 appenders specified in file for "com.metadatatechnology".

 Line 63: <root level="INFO">

Similar options for all remaining packages in the project, and third party libraries.

Tomcat files

In Apache Tomcat, various log files are generated during the execution of a Java web application. These log files provide valuable information about the application's behavior, errors, and performance. Here's a summary of some common log files in Tomcat:

   catalina.log:
       Purpose: General logging for the Tomcat server.
       Contents: Includes information about server startup, shutdown, and any errors that occur during the server's operation.
   catalina.<date>.log:
       Purpose: Daily rotating log file for Catalina.
       Contents: Includes information specific to the Catalina component of Tomcat. Useful for troubleshooting Catalina-related issues.
   localhost.log:
       Purpose: Logs information related to the default "localhost" context.
       Contents: Records information about the deployment and undeployment of web applications under the default context.
   localhost.<date>.log:
       Purpose: Daily rotating log file for the default "localhost" context.
       Contents: Contains information specific to the default web application context. Useful for troubleshooting application-specific issues.
   localhost_access_log.txt:
       Purpose: Records access information, such as requests made to the Tomcat server.
       Contents: Contains details like client IP address, request date and time, HTTP status, and bytes sent.
   localhost_access_log.<date>.txt:
       Purpose: Daily rotating log file for localhost_access_log
       Contents: The daily rotation of the localhost_access_log
   manager.log:
       Purpose: Logs information about the Tomcat Manager application.
       Contents: Records deployment and undeployment activities performed through the Tomcat Manager.
   host-manager.log:
       Purpose: Logs information about the Host Manager application.
       Contents: Records deployment and undeployment activities performed through the Host Manager.

Types of logs in Log File

Sample log entry:

 2024-01-30 13:34:41.123 INFO main com.example.MyClass - This is a log message

Every log entry consists of the following parts:

  1. Timestamp when error occurred (eg. 2024-01-30 13:34:41.123)
  2. Log level (eg. INFO)
  3. Thread on which log was produced (eg. main)
  4. Class that produced the log (eg. com.example.MyClass)
  5. Content of the log (eg. This is a log message)

There are multiple types of logs stored in FusionRegistry.log file. Some are more helpful for the end user than others.

System Information Logs

Those log entries inform about the state of the system, services being started etc. They are generally not very helpful for end users. Examples:

 2024-01-25 13:49:24.187 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.utils.spring.ApplicationStarterImpl - Starting class io.sdmx.core.dao.base.PersistableMaintainableDao
 2024-01-25 13:49:24.137 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.core.fmr.manager.settings.RegistryPropertiesFileManagerImpl - Set up Email Server Settings
 2024-01-25 13:49:24.115 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.fusion.audit.manager.log.LogManagerImpl - Max Age for Transactional Log Events set to -1 hours

Error/Warn Information Logs

If any issues were encountered, please attach logs to your report. Error log entities usually contain stack trace which is helpful for the development team to find the problem in code. Examples:

 2024-01-29 11:05:12.475 ERROR Thread-457 io.sdmx.api.exception.SdmxException - Can not delete mandatory attribute UNIT_MULT
 io.sdmx.api.exception.SdmxException: Can not delete mandatory attribute UNIT_MULT

at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.validateAttributes(ImportPreProcessorEngine.java:298) at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.validate(ImportPreProcessorEngine.java:253) at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.run(ImportPreProcessorEngine.java:99) at com.metadatatechnology.fusion.sdmx.jdbc.engine.ImportPreProcessorEngine.lambda$new$0(ImportPreProcessorEngine.java:75) at io.sdmx.fusion.audit.manager.event.AuditEventManager.lambda$startNewThread$7(AuditEventManager.java:308)

       ...
 2024-01-29 13:47:38.233 ERROR http-nio-8080-exec-5 io.sdmx.api.exception.SdmxException - unauthorised
 io.sdmx.api.exception.SdmxUnauthorisedException: unauthorised

at io.sdmx.api.security.ISecurityAdminAuthorisationManager.authorise(ISecurityAdminAuthorisationManager.java:33) at io.sdmx.api.security.ISecurityAdminAuthorisationManager.authorise(ISecurityAdminAuthorisationManager.java:45) at com.metadatatechnology.fusion.security.manager.settings.AbstractFusionSecurityRulesManager.checkAuth(AbstractFusionSecurityRulesManager.java:138) at com.metadatatechnology.fusion.security.manager.settings.AbstractFusionSecurityRulesManager.saveRule(AbstractFusionSecurityRulesManager.java:87) at com.metadatatechnology.fusion.security.service.GenericFusionSecurityRuleServiceActivator.saveRule(GenericFusionSecurityRuleServiceActivator.java:39)

       ...




Database Logging

There are also log tables within the database which persist some but not all of the logged information.

  • Log Tables
  • Audit Tables