IBM Business Analytics Proven Practices: IBM Cognos Dynamic Cube Advanced Logging Settings

Product(s): IBM Cognos Dynamic Cube; Area of Interest: Infrastructure

This document covers the tracing capabilities for Dynamic Cube. It covers how to set the logging, and all the options for logging in the file as well as a brief description of each event group and when to use them.

Share:

Joseph Ng, Advisory Software Engineer, IBM

Joseph Ng is an Advisory Software Engineer at IBM Silicon Valley Laboratory. He has over 12 years of software development experience and has spent the last 8 years at IBM. He was a member of the development team for IBM Alphablox and InfoSphere Warehouse Cubing Services and is currently a developer for IBM Cognos Dynamic Cubes. He holds a Bachelor's degree in Computer Science from the University of California, Berkeley, US.



21 August 2013

Also available in Spanish

Introduction

Purpose of Document

The purpose of this document is to provide guidance on enabling the advance logging settings for Dynamic Cubes and how to interpret the log messages which will help to diagnose various issues such as cube start problems, unexpected or wrong metadata, unexpected or wrong query results and poor query performance. This document will cover an introduction to event log groups, followed by detail about the log message format, and will continue with a description of the Dynamic Cubes default logging capabilities and an explanation about how to interpret the corresponding log messages. The document outlines the information that can be collected when enabling the advanced Dynamic Cubes logging event groups, the different log trace levels, and how to interpret the corresponding log messages.

Applicability

The techniques and settings described in this document apply to,

  • IBM Cognos Business Intelligence 10.2

In addition, later versions may have added or removed Dynamic Cubes logging event groups or changed specific logging messages. For further assistance or clarification please contact IBM Cognos Support for assistance. Also the user must have access to each server the IBM Cognos BI Dispatcher is installed on, as well as having the ability to stop and restart either the Query Service or the IBM BI Cognos Dispatcher.


Dynamic Cubes Logging Capabilities

Dynamic Cubes exists within the Dynamic Query Mode (DQM) server, therefore Dynamic Cubes leverage the same logging mechanism as the DQM server. Dynamic Cubes uses the concept of event groups to distinguish between the different areas of the Dynamic Cubes which can be logged. Furthermore, an event group can support five different logging levels.

Logging LevelDescription
noneNothing will be logged for this event group
errorLog messages about unrecoverable errors will be logged for this event group. Note that these error log messages are usually logged regardless if the event group has been enabled.
warnLog messages about recoverable errors will be logged for this event group
infoLog messages about various kinds of information will be logged for this event group
traceAll possible log messages for this event group will be logged. This log level is usually used for diagnostic purposes and should not be enabled in a normally operating production environment.

The event groups are set via a configuration file called xqe.diagnosticlogging.xml under the <Cognos Home Dir>\configuration directory. Unless a log appender is specified in the configuration file, the log entries are found in the <Cognos Home Dir>\logs\XQE directory in a file named xqelog-YYMMDD-xxxxxxxxxx, where xxxxxxxxxx is the difference between the time the log was created and Universal Time (UTC) in milliseconds.

To enable a specific event group find the <component name="XQE"> tag in the xqe.diagnosticlogging.xml file and add a new child tag with the following format:
<eventGroup name="Name of the Event Group" level="Logging Level"/>

Restart the IBM Cognos BI service or just the QueryService specifically for the DQM server to pick up the newly added event group.

The log file contains a timestamp since each time the QueryService is started/restarted in IBM Cognos Administration (and also if the IBM Cognos BI service is restarted) a new xqelog-YYMMDD-xxxxxxxxxx file is created. The timestamp allows the user to cross reference which log file is corresponds to which instance the QueryService was restarted. By default XQE log files rollover once the log file is over 10MB.

DQM and Dynamic Cubes will never delete existing XQE log files. It is up to the user to manage and delete old log files from the Cognos Home Dir>\logs\XQE directory when they are no longer required.


How to Read a Dynamic Cube Log Entry

This section will discuss some of the attributes of a Dynamic Cube log entry and their meaning. Consider the following sample log entry,

<event component="XQE" group="ROLAPCubes.Loader" level="ERROR" thread="1"
 timestamp="2013-03-28 01:13:30.892" contextId="17028" requestId="requestIDForValidation"
 rolapCube="Sales1_MUN_DB2" sessionId="f8b90254-4efc-4f33-98bb-181a0d168280">
<![CDATA[XQE-ROL-0095 The definition for the calculated member 'Product_Calc_MemberSet'
 is not valid. It has been removed from the hierarchy [Product].[Product (Sales1997)]…</event>

When reading a Dynamic Cube log entry there are some important things to note in order to diagnose problems and speed up time to resolution. First, note the value of the group attribute for the log entry. The value for this attribute will give you an indication of which area the log message relates to. In the sample above, the value is “ROLAPCubes.Loader” which indicates that the log message is related to cube loading.

Next, note the value of the level attribute for the log entry. The value for this attribute will give you an indication of the severity of the log message. In this case the value is “ERROR” which indicates that an unrecoverable error has occurred.

Next note the value of the rolapCube attribute. The value of this attribute tells you the specific Dynamic Cube the message pertains to. In this case the value indicates that the error occurred when loading the Dynamic Cube named ‘Sales1 MUN DB2’.

At this point note that the text between the <event> and </event> tags contains the detailed log message. In this log message the error is about an invalid calculated member definition for the calculated member named “Product_Calc_MemberSet”. Furthermore, the log message states that the calculated member has been removed from the hierarchy and will not appear in the cube. The solution for this issue would be to reopen the model for the Dynamic Cube named Sales1 MUN DB2 and correct the calculated member expression for the calculated member Product_Calc_MemberSet.

Other interesting attributes are timestamp and sessionId. Sometimes it is helpful to check the value of the timestamp to make sure the log entries are not too old or irrelevant and to check the value of the sessionId in order to cross reference all the other log messages that are related to that particular session.


Dynamic Cube Default Logging Capabilities

Error level log messages for specific Dynamic Cubes event groups are always enabled by default. The only non-error level Dynamic Cubes event group that is enabled by default is the ROLAPCubes.Info event group which has the logging level set to info.

The ROLAPCubes.Info event group enabled at the info log level will log various information about when a cube has been added, updated, loaded, enabled/disabled, or deleted from a Cognos BI server. Other types of log messages that apply to a specific cube include validation messages for the cube’s aggregate slices, signaling when the cube’s in-memory aggregates have begun loading, and signaling when the cube’s cache (member/data/security) has been successfully updated.


Dynamic Cube Advanced Logging Capabilities

Dynamic Cubes has 14 specific event groups that can enabled at the trace level for more detailed log messages.

Table 2 - Dynamic Cube Advanced Log Groups
Event groups
ROLAPCubes
ROLAPCubes.Loader
ROLAPCubes.Info
ROLAPCubes.Management
ROLAPCubes.Reservation
ROLAPCubes.Security
ROLAPCubes.FMAPI
ROLAPQuery
ROLAPQuery.Performance
ROLAPQuery.AggregateStrategy
ROLAPCubes.AggregateCache
ROLAPAggregateAdvisor
ROLAP.AggregateWorkload
ROLAPCubes.Virtual

ROLAPCubes

The ROLAPCubes event group enabled at the trace log level will log the total number of members in the member cache for a specific cube. This information is helpful when estimating how much JVM memory is needed for a cube and is an early indicator if the cube has been modeled correctly, since an incorrectly modeled cube would have a total number of cached members that is either more or less then what is expected.

ROLAPCubes.Loader

The ROLAPCubes.Loader event group logs messages related to the loading of a cube. By default, if errors are encountered when loading a calculated member or measure, a ROLAPCubes.Loader event group message is logged explaining why the calculated member or measures was invalid and discarded. By default a ROLAPCubes.Loader event group message is also logged if there is an error when attempting to assign a default member to a hierarchy. If the ROLAPCubes.Loader event group is enabled at the info log level, it will log various information including the relative time current period expressions, which hierarchies and levels have padding members, when a specific hierarchy is being loaded, what type of hierarchy is being loaded (level versus parent-child), the total number of members loaded for a specific hierarchy, and the time it takes to load a specific hierarchy.

The ROLAPCubes.Loader event group log messages are very helpful in diagnosing why a specific cube takes so long to load and why the members of a hierarchy appear the way they do in the metadata, especially if used in conjunction with the QueryService.SQL event group found in the same xqelog-YYMMDD-xxxxxxxxxx log file set at trace level. By looking at the log entries about when the member query has started and stopped loading a specific hierarchy, the user can determine how long it takes for a that hierarchy to fully load. Enabling the QueryService.SQL event group set at trace level will log the SQL queries that are being run to create the members for a hierarchy. Looking at the SQL will allow the user to determine if the hierarchy has been modeled correctly with the correct level keys and attributes.

Finally validating that the total number of members loaded for a specific hierarchy with the number of unique level keys in the dimension table is a good way to determine if the cube has been modeled correctly. In summary, it is helpful to enable the ROLAPCubes.Loader event group during the process of modeling, deploying, and publishing a cube and to then disable the event group once the cube has been validated as modeled and running correctly. The ROLAPCubes.Loader event group enabled at the trace log level will log more detailed information, including messages marking the start and end of the process to load a specific hierarchy and the time it takes to query the relational database for the members.

ROLAPCubes.Info

The ROLAPCubes.Info event group is set to the info level by default and there is no need to change the logging level unless the user wishes to disable the event group by removing the log group entry from the xqe.diagnosticlogging.xml file or setting the logging level to none.

ROLAPCubes.Management

The ROLAPCubes.Management event group logs messages related to the management of the cube. By default, if an error is encountered with setting one or more of the cube’s configuration parameters a ROLAPCubes.Management event message will be logged. The ROLAPCubes.Managerment event group enabled at the info level will log various information such as when a specific version of a data cache, member cache, or security cache is created, when a cube startup trigger starts and finishes, and other esoteric cube management information including Cognos BI inter-communication related to Dynamic Cubes.

Since most of the ROLAPCubes.Management event group log messages are esoteric, the only time this event group needs to be enabled is if a user is asked to do so by your local IBM Cognos Support group in order to diagnose a specific problem.

ROLAPCubes.Reservation

The ROLAPCubes.Reservation event group logs messages related to cube reservations. There exists a class of cube operations that when run concurrently require that they are run in a thread-safe manner. Locks/reservations are used to ensure thread safety. Since the ROLAPCubes.Reservation event group log messages are very esoteric, the only time this event group needs to be enabled is if a user is asked to do so by your local IBM Cognos Support group in order to diagnose a specific problem related to unexpected behavior during concurrent actions.

ROLAPCubes.Security

The ROLAPCubes.Security event group logs messages related to Dynamic Cubes security. When the ROLAPCubes.Security event group is enabled at a level of info, it will log details about the security views during startup of the cube. This includes if the cube has been granted all member access or all member denied and the total the number of members granted/denied. There will also be log messages with details about what expressions were run for the security views, how many members the individual views allowed and how many security views are loaded for the cube. This type of information can be helpful in determining how the different security views for a specific cube are interacting in combination and a quick way to check if the expected number of members have been granted or denied.

When the ROLAPCubes.Security event group is enabled at trace level it will log the names of the individual users who log on to the cube and the user’s role and views. There will also be log messages about the user’s specific security view combination and if the user can see all, some, or none of the hierarchy. This type of information can be helpful in determining why a specific user is seeing the wrong members in the cube due to an incorrect security combination.

ROLAPCubes.FMAPI

The ROLAPCubes.FMAPI event groups logs messages related to Cube Designer and the member browser of the cube. By default, if an error is encountered while handling the member browser requests from Cube Designer this event group will log a detailed error message in the log about the error. If a user encounters issues with the Cube Designer member browser functionality, this event group will help diagnose the problem.

ROLAPQuery

The ROLAPQuery event group logs messages related to when a query is executed against a Dynamic Cube. When the ROLAPQuery event group enabled at the trace level it will log details about the query such as the specific query that is about to be executed, details about measure pre-fetching, details about member predicate optimization, and if there are no results returned after executing the query. Unless you are only looking for specific information such as the V5 query, it is recommended that the ROLAPQuery.Performance event group and the ROLAPQuery event group be enabled at the trace level in order to debug Dynamic Cube query issues effectively.

ROLAPQuery.Performance

The ROLAPQuery.Performance event group logs messages related to query performance for Dynamic Cubes queries. The ROLAPQuery.Performance log entry introduces the op and duration attributes. The op attribute value is either START or END, allowing the user to see when a specific query action starts and ends in the log. The duration attribute value is the difference in time in milliseconds between the start and end of a specific query action.

When the ROLAPQuery.Performance event group is enabled at trace level it will log details about the query and the duration of time spent in specific areas of query execution. This kind of information is invaluable in debugging the performance of cube. By looking at the log entries and the execution times a user can determine the time spent in the areas of query planning/generation, the retrieval of values from the data cache, the retrieval of value from the aggregate cache, the execution of the SQL query, retrieval of data from the underlying RDBMS, and the storage of values into the data cache. The total query time is also helpful when compared against the time it takes for a report to display on the screen. This allows a user to determine if query performance issues are in the query engine layer or in the result transport and report rendering layers.

It is sometimes helpful to note what kind of log messages are logged or are unexpectedly missing between the START and END log messages for a specific query action. For example, if a user sees log messages pertaining to the execution of a SQL query and retrieval of data from the underlying RDBMS for a report that should be using the warm cache, this would be an indication that something is being stored incorrectly in the warm cache or that the user’s assumption that the report is leveraging the warm cache is incorrect. Pay special attention to the ROLAPQuery.Performance log message which logs the finished execution of QueryStrategy for a specific report like the one below,

<event component="XQE" group="ROLAPQuery.Performance" level="INFO" thread="78"
 timestamp="2013-04-08 12:41:44.347" op="END" duration="32" contextId="4"
 requestId="requestIDForValidation" rolapCube="GoSalesSample" sessionId="3af370b5:13dea8508b9:-7fd3">
<![CDATA[Finished execution of Query Strategy for report Measures_Measures
   Requested 100 tuples
   Found 50 tuples in data cache
   Found 0 tuples in aggregate cubes
   Fetched 50 tuples from database
   0 of the tuples were from pushdown queries
   Created 0 tuples from the aggregate cache
      Total time processing aggregates : 0 (ms) using 0 tasks
            0 aggregate cells rolled up into 0 separate locations
]]></event>

This log message includes a breakdown of the categories where the result tuples came from and how many tuples were returned per category.

Table 3 - Dynamic Cube Query Categories for Tuple Results
CategoryDetails
Data CacheTuple values from the in-memory data cache. The values are read from the in-memory data cache which is populated from previously run queries. This is considered data from a warm cache.
Aggregate CubeTuple values from the in-database aggregates. The values returned come from running a SQL query against the aggregate/summary tables found in the underlying RDBMS database.
DatabaseTuple values from running a SQL query against the underlying RDBMS database. This is considered data from a cold cache.
Pushdown QueryA subset of tuples values from running a JDBC query against the underlying RDBMS database in which the query is pushdown to the database. Pushdown queries are only supported in queries with FILTER, TOPCOUNT, or TOPSUM function calls.
Aggregate CacheTuple values from the in-memory aggregates. The values are read from the in-memory aggregate cache.

By looking at the breakdown of the different categories for a specific query, the user can determine if the query is being handled by the appropriate caches or database and in the right ratios.

ROLAPQuery.AggregateStrategy

The ROLAPQuery.AggregateStrategy event group enabled at trace level logs detail analysis about aggregates for a specific report. This information includes a log message about whether aggregates are not present for use by the report, which aggregates were considered for the report, which aggregates were used and finally which aggregates were rejected and the reason for the rejection.

If a specific report or query has poor performance because it is not using the expected aggregates, use the ROLAPQuery.AggregateStrategy event group enabled at a trace level.

ROLAPCubes.AggregateCache

The ROLAPCubes.AggregateCache event group logs numerous messages related to the different aspects of how the aggregate cache works. By default, the ROLAPCubes.AggregateCache event group is enabled at the error level and logs issues with reading the aggregate cache or if a specific aggregate does not completely solve an entire query. The ROLAPCubes.AggregateCache event group will also log a warning message when loading of an in-memory aggregate has been skipped because the max aggregate cache size is zero. This is a useful message to look for when in-memory aggregates are not being loaded for an unexpected reason.

When the ROLAPCubes.AggregateCache event group is enabled at an info level it will log different aspects pertaining to the loading of the aggregate cache. The messages are usually a two part message with a message marking the start of the aggregate loading and whether the loading was successful or unsuccessful. For example, when enabled at the info level the log could contain a message saying “beginning loading aggregate definition xyz” and then followed by a success message saying “loaded aggregate definition xyz with # of cells and # of bytes”.

It could also log messages about how many threads/tasks are being used to load the aggregate cache, total number of aggregate cells accessed, total aggregate storage size, if no aggregates are selected for a query, and the query set levels. This type of information is invaluable when debugging issues about reducing the time to load the aggregates, how much memory is needed for the aggregates, if reports are actually using aggregates, and if a specific query contains the members at the correct level for an aggregate to match.

When enabled at trace level, the ROLAPCubes.AggregateCache event group logs the result set returned from the aggregate cache and more detail information why specific aggregates were rejected. This information is very important in helping to craft better aggregates or to modify the reports so they will match the existing aggregates.

The ROLAPCubes.AggregateCache event group enabled at info or trace level will cause a lot of information to be logged. If the event group is enabled in conjunction with using an appender (see Appendix A), the main log file will be less cluttered. It is recommended that this event group only be used when required to investigate issues with the aggregate cache.

ROLAPAggregateAdvisor

The ROLAPAggregateAdvisor event group logs messages about how the aggregate advisor works and the errors that the advisor may encounter while attempting to recommend aggregates.

When the ROLAPAggregateAdvisor event group is enabled at an info level it will log information about the workflow that the advisor took to come up with its aggregate recommendations. This information is important when investigating why a specific aggregate advisor run is returning the wrong set of aggregates. For example, the event group would log messages like “aggregate xyz was rejected because it is too large compared to the fact table”. Such a message would mean that the cardinality of the aggregate needs to be reduced, perhaps by removing a dimension for the aggregate to be recommended.

ROLAP.AggregateWorkload

The ROLAP.AggregateWorkload event group enabled at info level or higher will enable workload logging for Dynamic Cubes queries. The workload logs are used by the Aggregate Advisor when determining aggregates. For more information about how the Aggregate Advisor uses workload logging see Optimize dynamic cube performance with Aggregate Advisor.

Another way to enable workload logging is to set the workload enabled property on the cube. The ROLAP.AggregateWorkload event group enabled at trace level will also log messages if issues are encountered with deleting workload log files.

ROLAPCubes.Virtual

The ROLAPCubes.Virtual event group logs various information about virtual cubes including how a virtual cube is initialized, how a virtual cube will merge its source cubes, what source objects are hidden (if any), and what queries are sent to the source cube. By default, the ROLAPCubes.Virtual event group will log warning messages such as when invalid source dimension, hierarchy, level, or members are detected during the creation of a virtual cube. It will also log the dead cube warning when a virtual hierarchy is created which does not have an ALL member and does not merge hierarchies from all the source cubes. This will result in a “dead” source cube since no queries will be routed to the cubes corresponding to the missing source hierarchies.

To help diagnose issues where a virtual cube is merging incorrectly or returning unexpected results like only returning data from one source cube, enable the ROLAPCubes.Virtual event group with the trace log level.

The event group will log detailed messages about how the source objects are being merged. If a dimension, hierarchy, level, or member is not merging properly the resulting virtual tuple log message could explain why queries are returning only the data from one source cube. Also look for log messages where one or more dimensions from a source cube are not merged, if a hierarchy is hidden and not defaulted, or a hierarchy is not hidden and defaulted. These cases could also cause a query not be run against a source cube.


Appendix A

The DQM logging mechanism has a log appender feature that allows users to redirect a specific event group log messages to a specific file rather than the standard xqelog-YYMMDD-xxxxxxxxxx file. In certain cases this is helpful because the standard xqelog-YYMMDD-xxxxxxxxxx file can become hard to parse if too many event groups are enabled and too many log messages are logged in the standard log file. By placing a specific event group log messages in a specific file the log messages are easier to parse. The drawback is separate log files make it harder to cross reference log messages when a user needs to see different event group log messages relative to one another.

To enable a log appender, add the attribute appender whose value is the name of the appender to the event group entry in the xqe.diagnosticlogging.xml file. For example,

<eventGroup name="ROLAPCubes.Info" appender=”DesiredAppenderName” level="info"/>

Next setup an appender in the xqe.diagnosticlogging.xml as follows, making sure the name attribute is exactly the same as the value specified above.

<appender name="DesiredAppenderName"
 class="com.cognos.xqe.trace.appender.XQEFileAppender">               
<param name="myAppender.log" value="DesiredAppenderFileName"/>
<param name="includeTimestamp" value="true"/>
	<param name="includeTimestampInFileName" value="true" />
</appender>

This will write log messages for the event group ROLAPCubes.Info to the file myAppender.log.

Resources

Comments

developerWorks: Sign in

Required fields are indicated with an asterisk (*).


Need an IBM ID?
Forgot your IBM ID?


Forgot your password?
Change your password

By clicking Submit, you agree to the developerWorks terms of use.

 


The first time you sign into developerWorks, a profile is created for you. Information in your profile (your name, country/region, and company name) is displayed to the public and will accompany any content you post, unless you opt to hide your company name. You may update your IBM account at any time.

All information submitted is secure.

Choose your display name



The first time you sign in to developerWorks, a profile is created for you, so you need to choose a display name. Your display name accompanies the content you post on developerWorks.

Please choose a display name between 3-31 characters. Your display name must be unique in the developerWorks community and should not be your email address for privacy reasons.

Required fields are indicated with an asterisk (*).

(Must be between 3 – 31 characters.)

By clicking Submit, you agree to the developerWorks terms of use.

 


All information submitted is secure.

Dig deeper into Big data and analytics on developerWorks


static.content.url=http://www.ibm.com/developerworks/js/artrating/
SITE_ID=1
Zone=Big data and analytics
ArticleID=941504
ArticleTitle=IBM Business Analytics Proven Practices: IBM Cognos Dynamic Cube Advanced Logging Settings
publish-date=08212013