Difference between revisions of "Logging"
Jump to navigation
Jump to search
(→Requesting Structural Metadata) |
|||
| (10 intermediate revisions by 2 users not shown) | |||
| Line 1: | Line 1: | ||
| + | [[Category:Installation_and_Configuration]] | ||
| + | [[Category:FMR_Configuration_Reference]] | ||
| + | [[Category:How_To]] | ||
| + | [[Category:How_To V11]] | ||
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. | 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 | + | Logging information is stored in the filesystem. The files on your system are temporary, and without intervention, they could be overwritten by more recent log data. This measure is in place to avoid log files occupying your entire disk space. |
| − | |||
=File-based logging= | =File-based logging= | ||
| Line 9: | Line 12: | ||
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. | 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. | ||
| + | |||
| + | ==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. | ||
| + | |||
| + | FusionRegistry.log: | ||
| + | Purpose: Logs Specific information about the Fusion Registry | ||
| + | Contents: This is the most useful log file when debugging an issue with the FMR. | ||
==Logback== | ==Logback== | ||
| Line 80: | Line 123: | ||
Similar options for all remaining packages in the project, and third party libraries. | Similar options for all remaining packages in the project, and third party libraries. | ||
| − | == | + | ==Log Detail== |
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | = | ||
Sample log entry: | Sample log entry: | ||
| Line 130: | Line 137: | ||
There are multiple types of logs stored in FusionRegistry.log file. Some are more helpful for the end user than others. | There are multiple types of logs stored in FusionRegistry.log file. Some are more helpful for the end user than others. | ||
| − | ==System Information Logs== | + | ===System Information Logs=== |
| − | Those log entries inform about the state of the system, services being started | + | Those log entries inform about the state of the system, services being started or system settings being set. 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.187 INFO RMI TCP Connection(3)-127.0.0.1 io.sdmx.utils.spring.ApplicationStarterImpl - Starting class io.sdmx.core.dao.base.PersistableMaintainableDao | ||
| Line 139: | Line 146: | ||
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 | 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 | ||
| − | = | + | ===Loading Structural Metadata=== |
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | |||
| − | ==Loading Structural Metadata== | ||
When loading structural metadata into the registry, many log entries are created. They have an INFO level and may contain the url from which the metadata is loaded, identifiers of loaded metadata as well as process description. Example: | When loading structural metadata into the registry, many log entries are created. They have an INFO level and may contain the url from which the metadata is loaded, identifiers of loaded metadata as well as process description. Example: | ||
| Line 182: | Line 167: | ||
2024-01-29 10:55:02.332 INFO http-nio-8080-exec-6 io.sdmx.core.dao.base.PersistableMaintainableDao - Save Structure 'urn:sdmx:org.sdmx.infomodel.codelist.Codelist=ISO:COUNTRY_ALPHA3(1.0)' | 2024-01-29 10:55:02.332 INFO http-nio-8080-exec-6 io.sdmx.core.dao.base.PersistableMaintainableDao - Save Structure 'urn:sdmx:org.sdmx.infomodel.codelist.Codelist=ISO:COUNTRY_ALPHA3(1.0)' | ||
| − | ==Saving Time-Series Data== | + | ===Saving Time-Series Data=== |
When inserting/modifying/replacing data using url or file there are many log entries created. They have an INFO level and contain step by step process description. Example: | When inserting/modifying/replacing data using url or file there are many log entries created. They have an INFO level and contain step by step process description. Example: | ||
| Line 200: | Line 185: | ||
2024-01-29 11:03:27.289 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.mysql.MySqlDBulkLoadDao - Bulk Load Complete | 2024-01-29 11:03:27.289 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.mysql.MySqlDBulkLoadDao - Bulk Load Complete | ||
| − | ==Creating a Data Store== | + | ===Creating a Data Store=== |
When creating data storage from an admin panel in the system there are many log entries created. They have an INFO level, and contain information about database configuration provided by the user. Example: | When creating data storage from an admin panel in the system there are many log entries created. They have an INFO level, and contain information about database configuration provided by the user. Example: | ||
| Line 209: | Line 194: | ||
2024-01-29 11:00:05.355 INFO http-nio-8080-exec-5 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - SQL In Argument Limit: 1000 | 2024-01-29 11:00:05.355 INFO http-nio-8080-exec-5 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - SQL In Argument Limit: 1000 | ||
| − | == Requesting Structural Metadata== | + | === Requesting Structural Metadata=== |
When requesting for metadata in the system there are log entries created. They have an INFO level, and contain information about what resource was requested, and if the result was returned from the database or from the cache. | When requesting for metadata in the system there are log entries created. They have an INFO level, and contain information about what resource was requested, and if the result was returned from the database or from the cache. | ||
| Line 225: | Line 210: | ||
2024-01-29 10:56:24.843 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed | 2024-01-29 10:56:24.843 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed | ||
| − | ==Requesting Time-Series Data== | + | ===Requesting Time-Series Data=== |
When requesting for time series in the system there are log entries created. They have an INFO level, and contain information about what resource was requested. If the request is against an external database the query may well include SQL statements showing the database queries performed. | When requesting for time series in the system there are log entries created. They have an INFO level, and contain information about what resource was requested. If the request is against an external database the query may well include SQL statements showing the database queries performed. | ||
| Line 238: | Line 223: | ||
2024-01-29 13:43:43.033 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed | 2024-01-29 13:43:43.033 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed | ||
| − | = | + | ===Error/Warn Information Logs=== |
| + | If any issues were encountered, please attach logs to your report. Error log entities usually contain stack-trace which may be helpful to the development team to locate the issue in the 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) | ||
| + | ... | ||
Latest revision as of 07:52, 1 April 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. The files on your system are temporary, and without intervention, they could be overwritten by more recent log data. This measure is in place to avoid log files occupying your entire disk space.
Contents
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.
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.
FusionRegistry.log:
Purpose: Logs Specific information about the Fusion Registry
Contents: This is the most useful log file when debugging an issue with the FMR.
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.
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.
Log Detail
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 or system settings being set. 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
Loading Structural Metadata
When loading structural metadata into the registry, many log entries are created. They have an INFO level and may contain the url from which the metadata is loaded, identifiers of loaded metadata as well as process description. Example:
2024-01-29 10:54:55.998 INFO http-nio-8080-exec-3 io.sdmx.utils.http.broker.RestMessageBroker - Call URL: https://demo11.metadatatechnology.com/FusionRegistry/sdmx/v2/structure/structure/all/all/all/?format=sdmx-3.0 2024-01-29 10:54:57.624 INFO http-nio-8080-exec-3 io.sdmx.utils.http.broker.RestMessageBroker - Call URL Complete: https://demo11.metadatatechnology.com/FusionRegistry/sdmx/v2/structure/structure/all/all/all/?format=sdmx-3.0 2024-01-29 10:54:57.754 INFO http-nio-8080-exec-3 io.sdmx.core.sdmx.manager.structure.StructureReaderManagerImpl - Parse structures 2024-01-29 10:54:57.755 INFO http-nio-8080-exec-3 io.sdmx.format.ml.factory.structure.SdmxMLStructureReaderFactory - Read SdmxBeans using io.sdmx.format.ml.engine.structure.reader.v3.StaxStructureReaderEngineV3 2024-01-29 10:54:57.925 INFO http-nio-8080-exec-3 io.sdmx.core.sdmx.manager.structure.StructureReaderManagerImpl - Build Beans Complete 2024-01-29 10:54:57.926 INFO http-nio-8080-exec-3 io.sdmx.core.sdmx.manager.structure.StructureReaderManagerImpl - Post-Process Beans 2024-01-29 10:54:57.927 INFO http-nio-8080-exec-3 io.sdmx.core.sdmx.manager.structure.StructureReaderManagerImpl - Parse Structures Complete 2024-01-29 10:54:57.948 INFO http-nio-8080-exec-3 io.sdmx.core.structure.manager.persist.StructurePreProcessManagerImpl - Pre-process Beans Event 2024-01-29 10:54:57.949 INFO http-nio-8080-exec-3 io.sdmx.core.fmr.engine.structure.RegistryStructureValidationEngine - Validate structures for insertion 2024-01-29 10:54:58.021 INFO http-nio-8080-exec-3 io.sdmx.core.fmr.engine.structure.RegistryStructureValidationEngine - Validate Structure for Insertion:urn:sdmx:org.sdmx.infomodel.base.DataProviderScheme=EAPRO:DATA_PROVIDERS(1.0) ... 2024-01-29 10:54:58.051 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.registry.manager.persistence.PersistedStructureManagerEnterprise - structures valid, save to database 2024-01-29 10:54:58.051 INFO http-nio-8080-exec-3 io.sdmx.core.fmr.manager.persistence.AbstractPersistenceManager - Process Cross References 2024-01-29 10:54:58.060 INFO http-nio-8080-exec-3 io.sdmx.core.structure.manager.persist.StructurePreProcessManagerImpl - Pre-process Beans Event 2024-01-29 10:54:58.065 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.registry.manager.persistence.PersistedStructureManagerEnterprise - Save Successful - Publish Message 2024-01-29 10:55:02.287 INFO http-nio-8080-exec-6 io.sdmx.core.dao.base.PersistableMaintainableDao - Save Structure 'urn:sdmx:org.sdmx.infomodel.base.DataProviderScheme=EAPRO:DATA_PROVIDERS(1.0)' 2024-01-29 10:55:02.332 INFO http-nio-8080-exec-6 io.sdmx.core.dao.base.PersistableMaintainableDao - Save Structure 'urn:sdmx:org.sdmx.infomodel.codelist.Codelist=ISO:COUNTRY_ALPHA3(1.0)'
Saving Time-Series Data
When inserting/modifying/replacing data using url or file there are many log entries created. They have an INFO level and contain step by step process description. Example:
2024-01-29 11:03:26.258 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.generic.GenericDataLoadDao - Start Loading Dataset '-2662089662959301465' valid from '2024-01-29 11:03:26.0' valid to '2999-12-31 01:00:00.0' 2024-01-29 11:03:26.265 INFO Thread-9 com.metadatatechnology.fusion.core.data.engine.writer.timeseries.PercentageCompleteWriterEngine - 1.0011855% complete 2024-01-29 11:03:26.265 INFO Thread-33 com.metadatatechnology.fusion.registry.manager.data.publish.impl.ImportProcessorEngine - Percentage Complete: 1% 2024-01-29 11:03:26.270 INFO Thread-9 com.metadatatechnology.fusion.core.data.engine.writer.timeseries.PercentageCompleteWriterEngine - 2.002371% complete 2024-01-29 11:03:26.270 INFO Thread-35 com.metadatatechnology.fusion.registry.manager.data.publish.impl.ImportProcessorEngine - Percentage Complete: 2% 2024-01-29 11:03:26.273 INFO Thread-9 com.metadatatechnology.fusion.core.data.engine.writer.timeseries.PercentageCompleteWriterEngine - 3.0035567% complete ... com.metadatatechnology.fusion.core.data.engine.writer.timeseries.PercentageCompleteWriterEngine - 99.11737% complete 2024-01-29 11:03:26.386 INFO Thread-229 com.metadatatechnology.fusion.registry.manager.data.publish.impl.ImportProcessorEngine - Percentage Complete: 99% 2024-01-29 11:03:26.387 INFO Thread-231 com.metadatatechnology.fusion.registry.manager.data.publish.impl.ImportProcessorEngine - Percentage Complete: 100% 2024-01-29 11:03:26.402 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.engine.TransactionalDataWriterEngine - Commit data 2024-01-29 11:03:27.264 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.mysql.MySqlDBulkLoadDao - Perform Commit 2024-01-29 11:03:27.287 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.mysql.MySqlDBulkLoadDao - Final Commit 2024-01-29 11:03:27.289 INFO Thread-9 com.metadatatechnology.fusion.sdmx.jdbc.dao.publish.mysql.MySqlDBulkLoadDao - Bulk Load Complete
Creating a Data Store
When creating data storage from an admin panel in the system there are many log entries created. They have an INFO level, and contain information about database configuration provided by the user. Example:
2024-01-29 11:00:05.245 INFO http-nio-8080-exec-5 com.metadatatechnology.fusion.registry.manager.data.publish.impl.DataSourceManagerImpl - Create datasource: root@localhost:3306/fmr_data 2024-01-29 11:00:05.247 INFO http-nio-8080-exec-5 io.sdmx.utils.hibernate.model.PersistantStoragePlatform - Constructed URL: jdbc:mysql://localhost:3306/fmr_data 2024-01-29 11:00:05.328 INFO http-nio-8080-exec-5 com.metadatatechnology.fusion.registry.manager.data.publish.impl.DataSourceManagerImpl - Cache DataSource: root@localhost:3306/fmr_data 2024-01-29 11:00:05.330 INFO http-nio-8080-exec-5 io.sdmx.utils.hibernate.model.PersistantStoragePlatform - Constructed URL: jdbc:mysql://localhost:3306/fmr_data 2024-01-29 11:00:05.355 INFO http-nio-8080-exec-5 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - SQL In Argument Limit: 1000
Requesting Structural Metadata
When requesting for metadata in the system there are log entries created. They have an INFO level, and contain information about what resource was requested, and if the result was returned from the database or from the cache.
Examples:
2024-01-26 13:35:27.894 INFO http-nio-8080-exec-10 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request issued for: http://localhost:8080/FusionRegistry/sdmx/v2/structure/provisionagreement/*/*/* 2024-01-26 13:35:27.939 INFO http-nio-8080-exec-10 com.metadatatechnology.fusion.rest.manager.cache.SDMXRESTGetRequestCacheManager - Cache miss structure/provisionagreement/*/*/*?format=fusion-json&includeAllAnnotations=true&includeMetadata=true 2024-01-26 13:35:27.980 INFO http-nio-8080-exec-10 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed
2024-01-29 08:31:34.651 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request issued for: http://localhost:8080/FusionRegistry/sdmx/v2/structure/datastructure/*/*/* 2024-01-29 08:31:34.674 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.rest.manager.cache.SDMXRESTGetRequestCacheManager - Cache miss structure/datastructure/*/*/*?detail=allstubs&format=fusion-json&includeAllAnnotations=true&includeMetadata=true 2024-01-29 08:31:34.710 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed
com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request issued for: http://localhost:8080/FusionRegistry/sdmx/v2/structure/dataproviderscheme/WB/DATA_PROVIDERS/1.0/WB 2024-01-29 10:56:24.812 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.rest.manager.cache.SDMXRESTGetRequestCacheManager - Cache miss structure/dataproviderscheme/WB/DATA_PROVIDERS/1.0/WB?format=fusion-json&includeAllAnnotations=true&includeMetadata=true 2024-01-29 10:56:24.843 INFO http-nio-8080-exec-3 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed
Requesting Time-Series Data
When requesting for time series in the system there are log entries created. They have an INFO level, and contain information about what resource was requested. If the request is against an external database the query may well include SQL statements showing the database queries performed.
2024-01-29 13:43:42.911 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request issued for: http://localhost:8080/FusionRegistry/sdmx/v2/data/dataflow/BIS/WS_SPP/1.0/ 2024-01-29 13:43:42.933 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.rest.manager.cache.SDMXRESTGetRequestCacheManager - Cache miss data/dataflow/BIS/WS_SPP/1.0?c[FREQ]=Q&c[REF_AREA]=5R&c[UNIT_MEASURE]=771&c[VALUE]=N&format=sdmx-compact-2.1&saveAs=BIS property prices: selected series 2024-01-29 13:43:42.934 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.core.data.manager.index.IndexRetrievalManagerImpl - Data Query By Provision Agreement:urn:sdmx:org.sdmx.infomodel.registry.ProvisionAgreement=BIS:WS_SPP_BIS(1.0) 2024-01-29 13:43:42.950 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - Execute Query against 'fmr_data' : SELECT ID, FR_GROUP_ID, FR_GROUP_ID, K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE FROM `BIS_WS_SPP_1_0_KEY` K WHERE FR_GROUP_ID != ? AND ((FR_PROVIDER_ACY = ? AND FR_PROVIDER_ID = ? )) AND K.FREQ IN (?,? ) AND K.REF_AREA IN (?,? ) AND K.UNIT_MEASURE IN (?,? ) AND K.VALUE IN (?,? ) with parameters, ^,BIS,BIS,^,Q,^,5R,^,771,^,N 2024-01-29 13:43:42.954 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - Completed Query against 'fmr_data', Processed '0' Table Rows for query: SELECT ID, FR_GROUP_ID, FR_GROUP_ID, K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE FROM `BIS_WS_SPP_1_0_KEY` K WHERE FR_GROUP_ID != ? AND ((FR_PROVIDER_ACY = ? AND FR_PROVIDER_ID = ? )) AND K.FREQ IN (?,? ) AND K.REF_AREA IN (?,? ) AND K.UNIT_MEASURE IN (?,? ) AND K.VALUE IN (?,? ) with parameters, ^,BIS,BIS,^,Q,^,5R,^,771,^,N 2024-01-29 13:43:42.957 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - Execute Query against 'fmr_data' : SELECT K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE, K.BREAKS, K.COVERAGE, K.TITLE_TS, K.FR_UPDATED_DATE, K.ID, O.OBS_VALUE, O.OBS_STATUS, O.OBS_CONF, O.OBS_PRE_BREAK, O.FR_DATASET_ID, O.FR_IS_DELETED, O.FR_UPDATED_DATE_OBS, O.FR_VALID_FROM, O.TIME_PERIOD, O.FR_OBS_DATE FROM `BIS_WS_SPP_1_0_OBS` O RIGHT JOIN (SELECT K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE, K.BREAKS, K.COVERAGE, K.TITLE_TS, K.FR_UPDATED_DATE, K.ID FROM `BIS_WS_SPP_1_0_KEY` K WHERE ((FR_PROVIDER_ACY = ? AND FR_PROVIDER_ID = ? )) AND K.FREQ = ? AND K.REF_AREA = ? AND K.UNIT_MEASURE = ? AND K.VALUE = ? AND K.FR_UPDATED_DATE IS NOT NULL AND K.FR_GROUP_ID = ? ) K ON O.FR_KEY_ID = K.ID WHERE (O.FR_VALID_TO = ? OR O.FR_VALID_TO IS NULL) AND O.FR_IS_DELETED=0 ORDER BY K.ID ASC,O.FR_OBS_DATE ASC with parameters, BIS,BIS,Q,5R,771,N,^,2999-12-30T23:00:00 2024-01-29 13:43:42.962 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.sdmx.jdbc.dao.MatrixPluginDao - Completed Query against 'fmr_data', Processed '0' Table Rows for query: SELECT K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE, K.BREAKS, K.COVERAGE, K.TITLE_TS, K.FR_UPDATED_DATE, K.ID, O.OBS_VALUE, O.OBS_STATUS, O.OBS_CONF, O.OBS_PRE_BREAK, O.FR_DATASET_ID, O.FR_IS_DELETED, O.FR_UPDATED_DATE_OBS, O.FR_VALID_FROM, O.TIME_PERIOD, O.FR_OBS_DATE FROM `BIS_WS_SPP_1_0_OBS` O RIGHT JOIN (SELECT K.FREQ, K.REF_AREA, K.VALUE, K.UNIT_MEASURE, K.BREAKS, K.COVERAGE, K.TITLE_TS, K.FR_UPDATED_DATE, K.ID FROM `BIS_WS_SPP_1_0_KEY` K WHERE ((FR_PROVIDER_ACY = ? AND FR_PROVIDER_ID = ? )) AND K.FREQ = ? AND K.REF_AREA = ? AND K.UNIT_MEASURE = ? AND K.VALUE = ? AND K.FR_UPDATED_DATE IS NOT NULL AND K.FR_GROUP_ID = ? ) K ON O.FR_KEY_ID = K.ID WHERE (O.FR_VALID_TO = ? OR O.FR_VALID_TO IS NULL) AND O.FR_IS_DELETED=0 ORDER BY K.ID ASC,O.FR_OBS_DATE ASC with parameters, BIS,BIS,Q,5R,771,N,^,2999-12-30T23:00:00 2024-01-29 13:43:43.032 ERROR http-nio-8080-exec-7 io.sdmx.format.ml.engine.error.ErrorWriterEngineV21 - No results for query 2024-01-29 13:43:43.033 INFO http-nio-8080-exec-7 com.metadatatechnology.fusion.registry.filter.FusionRegistryHTTPDataCacheHeaderFilter - Request completed
Error/Warn Information Logs
If any issues were encountered, please attach logs to your report. Error log entities usually contain stack-trace which may be helpful to the development team to locate the issue in the 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)
...
