Difference between revisions of "Logging"

From FMR Knowledge Base
Jump to navigation Jump to search
(→‎File-based logging)
 
(26 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 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.
+
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.
−
 
−
==Logback==
 
−
 
−
The logging is controlled by a file called "logback.xml"
 
−
 
−
Configuration can be done through the file level - this makes it permanent of you can use the UI.  This will not persist across
 
−
 
−
It is not recommended to switch to DEBUG level unless specifically requested to by the development team, since the amount of logging produced can be excessive and can cause performance issues
 
  
 
==Tomcat files==
 
==Tomcat files==
Line 54: Line 49:
 
         Contents: Records deployment and undeployment activities performed through the Host Manager.
 
         Contents: Records deployment and undeployment activities performed through the Host Manager.
  
−
=Database Logging=
+
    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.<br>
 +
'''DEBUG''': Helpful in tracking the flow through the system and isolating issues, especially during the development and QA phases.<br>
 +
'''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.<br>
 +
'''WARN''': An unexpected technical or business event happened, customers may be affected, but probably no immediate human intervention is required.<br>
 +
'''ERROR''': The system is in distress, customers are probably being affected (or will soon be) and the fix probably requires human intervention.<br>
 +
'''OFF''': This level is intended to turn off logging.<br>
 +
 
 +
'''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.'''
 +
 
 +
[[File: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.
 +
 
 +
==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)
 +
      ...
  
−
There are also log tables within the database which persist some but not all of the logged information.
+
  2024-01-29 13:47:38.233 ERROR http-nio-8080-exec-5 io.sdmx.api.exception.SdmxException - unauthorised
−
* Log Tables
+
  io.sdmx.api.exception.SdmxUnauthorisedException: unauthorised
−
* Audit Tables
+
      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 08: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.

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.

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.

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:

  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 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)
     ...
Retrieved from "https://fmrwiki.sdmxcloud.org/index.php?title=Logging&oldid=7561"