BAM Log Analysis

With the help of the BAM system, the Ometa framework has a very extensive logging feature. However, the BAM Dashboard cannot show a complete overview on the performance of method execution or specific issues like interface kills/startup turnarounds. To extract those kinds of information from BAM, it is almost obligatory to run SQL queries on the BAM database.

To avoid accessing the BAM database directly, a new system object Ometa.BAM.LogAnalysis is added which provides several pre-made methods to assist with these analysis activities.

Note

The timestamps in the Excel reports are presented in local time from the Framework Server.

BAM ODBC Profile

As with any other method in the framework, you need a profile with the connection information to run these reporting BAM log methods. If no profile exists yet with the connection information to the BAM database, create one.

Note

The BAM ODBC Profile must use the SQL Server ODBC Driver because it relies on the datetimeoffset column type. Refer to the Which ODBC Driver to Use article for more information.

The screenshot below shows an example of such a profile.

Reporting Methods

Knowing exactly what each method returns of information, is important to interpret the results correctly. The following paragraphs provide a short description of each of them.

Input Date Range and BAM Extraction Execution Times

Warning

Having a couple of million of rows in the BAM database is quite common. Some BAM queries can take a while executing before returning the result. Therefore, it is strongly advised to limit the data range over which the methods run, at most to 24 hours (one day).

Taking a longer timespan should only be used if it is known upfront that the BAM logging table contains a rather small amount of rows.

Every BAM analysis query has 2 input fields (some queries have a few more inputs):

• Start Range Timestamp: sets the beginning of the date range.
• End Range Timestamp: sets the end of the date range.

To make sure the date range is provided correctly, the field End Range Timestamp has an extra validation check so that it will always be larger (= later) than the Start Range Timestamp.

Common output fields

On the object, several fields are defined of which most are shared between at least 2 or more methods. With this approach, an attempt is made to generalise the interpretation of the output across the analysis queries.

Detailed description of some of those fields:

• Timestamp: the timestamp of the logging of the event (= the source of logging). This is not the time of the event itself.
• Correlation ID and Parent Correlation ID: identifiers link logged events between different processes of the framework in a tree-like fashion.
• Process Name: executable name of the process that has logged the event. This can be the name of an interface (bcs_*.exe), bcm.exe or others.

Method Get BCA Health Reports

Reports the BCA status information regarding connected BCM processes.

Additional output fields:

• Pending BCM Accepts: whether any acceptations from BCM requests were still pending at the moment.
• Connected BCMs: the number of BCM's connected at the time of BCA health reporting.
• Available Completion Port Threads: the total available number of connection handling worker threads at time of logging.

Method Get BCM Health Reports

With this method all BCM health counters of the running framework can be followed over time.

Additional output fields:

• Total Private Memory In Use Kb: the total memory in use by all framework processes, reported in Kilobytes.
• Total Processes CPU Percentage In Use: the total CPU percentage usage of all framework processes.
• Connected BCM Count: the total number of BCM threads connected to clients.
• Active BCM Count: number of active running BCM threads.

Method Get BCM Slot Requests

Returns all active BCM slots with their activity duration and which methods were run during those actions.

Additional output fields:

• Active Duration: the full duration a slot was active, in seconds.
• Thread ID: the internal thread ID used for the BCM slot.
• Total Method Executions: the total number of methods executed during the existence of the slot.

Method Get BCM Startups

Lists all newly started BCM processes.

Additional output fields:

• Thread ID: the internal ID of the BCM slot thread.

Method Get Data Model Excess Load Times

This method displays a list of all processes that took longer than a prescribed timespan (+/- 1 second) to connect to any system database (framework or case management) and to load the corresponding data model in memory.

Additional output fields:

• Process Name: the name of the executable file used to start the process.
• Process ID: the internal Windows process ID of the process.
• Connection Time Seconds: the time it took to connect to the database and load the data model, in seconds.
• Connection Destination: type identification to which database the connection was made. FW = framework database, DCS = case management database.

Method Get DCS Case Saving Times

Retrieves a list of DCS timings that show how long it takes for the system to save case information.

Additional output fields:

• Case ID: the internal ID of a case within DCS.
• Execution Duration: total number of seconds it takes to save a case.
• Case Display Name: the name of the case as shown to end-users.
• Message: a log message of the save action.

Method Get Full DCS Actions List By Case Id

Shows all internal logging of a full save action for a particular case within the given time range. This logging information can only be retrieve on a per-case basis.

Note

This information can only be retrieved when VERBOSE logging has been enabled for that specific period of time.

Additional input fields:

• Case ID: the internal ID of a case.

Additional output fields:

• Process Name: the name of the framework process handling the DCS actions.
• Message: an explanatory message stating the action being done for that case.

Warning

When attempting to capture VERBOSE logging to extract this information, be aware that VERBOSE logging can and will generate a very large amount of data. Therefor, let the framework only generate that logging for a short timeframe to investigate specific behaviour.

Method Get Interface Kills Memory Exceeded

Shows all interface processes (= connectors) that were killed by the framework due to having exceeded the maximum memory usage during 3 framework checks.

Additional output fields:

• Process Name: the name of the interface process.
• Max Memory Usage: the maximum amount of memory an interface process is allowed to use, in megabytes.
• Process Memory Usage: the memory in use at the moment the process was killed, in megabytes.

Method Get Interface Requests

Lists all requests made to interfaces with their activity duration and which methods were run during those actions.

Additional output fields:

• Active Duration: the full duration an interface was active, in seconds.
• Process ID: the Windows process ID used for the interface process.
• Thread ID: internal thread ID.
• Executed Methods: a list of all methods executed, separated by semicolons.
• Tracking End Message: the type of message that ended the duration tracking within the request. Is one of these: Interface freed, Interface closed or Interface disconnected.

Method Get Interface Startups

Lists all new started interfaces with type information.

Additional output fields:

• Process Name: the name of the interface process.

Method Get Interrupted Methods

Lists all methods that were started but for whatever reason were stopped prematurely.

Additional output fields:

• Process Name: the name of the interface process.
• Process ID: the Windows process ID used for the interface process.
• Thread ID: internal thread ID.
• Method: name of the interrupted method.

Note

This report may return records for methods that aren't interrupted but are/were still running at the moment of report generations, because they were started before the end date but did not complete before that.

Method Get Logging By Message And Component

Gives a full list of logging based on the filtered values of message and component, within the given time range.

Additional input fields:

• Message: search value to look for in the message logging.
• Component: search value to look for in the component field of the logging.

Tip

There is no need to enter a full message or component search value. A part of a message or component will return all logging records containing the search values.

When both message and component search values are provided, the method will look for both values at the same time. The search is an 'AND', not an 'OR' operation.

Entering no search values will result in returning all logging records found in the log table in the stated time range.

Warning

Be cautious with the search values and time range. This method can take a while to execute if the search conditions are set too broad.

The field Component used to be called Title in the pre-v5 framework versions.

Additional output fields:

• Message: the full message of the log record.
• Component: the full component.
• Severity: log level of the log record, like 'Information', 'Warning', 'Error', ...

Example, with input value 'Fetching' in field Message:

Method Get Method Execution Times

Returns a full list of executed methods, including data extensions, with execution times for each method.

Additional output fields:

• Method: name of the method that was executed.
• Object: name of the object containing the method.
• Profile: name of the profile used to execute the method.
• Execution Duration: total number of seconds used to execute the method. In case of methods with data extensions, the amount of time comprises of both the main method and the extensions together.
• Main Method: in case of a data extension, the name of the main method is shown here.

Method Get Method Execution Times By Template

Important

This method is currently disabled, meaning it won't return any data.

An issue with a data extension on this method prevents it from executing properly. This is an temporary issue and will be resolved in one of the next framework releases. . Until then, use the Report Extraction to generate an Excel report from the method Get Method Execution Times and apply the required filtering on the profile names there.

Similar to Get Method Execution Times.

Returns a full list of executed methods, including data extensions, of a particular template with execution times for each method.

Additional input fields:

• Templates: provide a template name or a list of template names. The entered names must correspond exactly to the names as defined in the templates master data. Multiple templates must be separated by a comma or ';#'.
• Profile List: this field can be ignored. Its context value will be set by an input extension Retrieve All Profiles By Template.

Additional output fields:

• Method: name of the method that was executed.
• Object: name of the object containing the method.
• Profile: name of the profile used to execute the method.
• Execution Duration: total number of seconds used to execute the method. In case of methods with data extensions, the amount of time comprises of both the main method and the extensions together.
• Main Method: in case of a data extension, the name of the main method is shown here.

Note

When no template name is given, none could not be found, or when no profiles linked to the given template names, no result will be returned.

Method Get Occurred Deadlocks

Shows a list of all deadlocks that occurred on the framework solution, mainly the Case Management database.

Additional output fields:

• Error Message: the error message logged as part of the deadlock.
• Process Name: the name of the interface process executing the SQL query that got deadlocked.
• Message: general message signaling the deadlock.

Method Get Occurred Errors

Shows a list of all errors that occurred during the framework operation.

Warning

Not every single log line signifies a single error. Multiple output lines can and will point to one and the same error within the solution.

Additional output fields:

• Error Message: the error message logged.
• Process Name: the name of the interface process during which operation the error occurred.
• Message: additional logged error information.

Method Get Occurred Time Outs

List all method time outs that occurred on the framework solution.

Additional output fields:

• Error Message: the error message occurred during the time out.
• Method: name of the method that was executing.
• Object: name of the object containing the method.
• Profile: name of the profile used to execute the method.
• Process Name: the name of the interface process executing the method.
• Message: additional time out error information.

Method Get Realtime Notification Durations

Provides a list of realtime key notification durations triggered by methods.

Additional output fields:

• Trigger Method: name of the method that triggered the notification.
• Notification Duration: time that is needed to send out the notifications to all ADM clients, in seconds.
• Thread ID: internal thread ID.

Method Get Caching Reads

Reports method calls that reused output using caching.

Additional output fields:

• Method: name of the method that was executed.
• Object: name of the object containing the method.
• Profile: name of the profile used to execute the method.
• Output: the directory in the WorkDir where the cached output was stored. If the cache entry is still valid, you can find the database entry in [cache].[CacheEntries] using this output.
• Message: the message of the caching action, see below for more information.
• Cache Entry Hash: the hash code representing the input context for the cache entry. This is used to match with the correct stored caching entry. The hashcode is created from the profile name, and the fields that were added as Input Context in the caching settings of the method.
• ValidUntil: the expiration date of the cache entry that is read from, in local system time, same timezone as the Timestamp.
• Includes Merged Extensions: flag indicating if a cache entry was found that included extension data in the output. This can only happen if the method has extensions, and the extensions themselves are also cached. Refer to Output Caching on Methods for details on caching in combination with extensions.

Either of the following messages can be logged:

• Skipping full method execution routine, entry was found in the cache.: the output from the cache can be used and directly returned. If the method has extensions, this means that the extensions were also cached and are included in the output.
• Skipping method execution, entry was found in the cache.: the output for a single method was found in the cached and is reused. This is logged if the method is executed by another method due to one of the following: extensions, post execution, audit trail, realtime keys. Refer to Output Caching on Methods for details on caching in combination with extensions.

Every method call that was resolved using caching will increase the usage counter of that entry. If a specific entry was used twice or more, it is eligible to be automatically refreshed when expiring. This means that the framework will execute the method a minute before the cache entry expires. The usages can be tracked in the database, however, this is done asynchronously and can have some delay.

Method Get Caching Writes

Reports method calls that were stored into the cache after execution.

Additional output fields:

• Method: name of the method that was executed.
• Object: name of the object containing the method.
• Profile: name of the profile used to execute the method.
• IsCacheRenewal: indicates if a cache renewal was forced, meaning that the method executes and refreshes the cache regardless of existing caches. This can be done by either:
  • the built-in automatic cache renewal: this executes the method automatically one minute before the cache expires if the cache was used more than once.
  • specifying context field Ometa.IsCacheRenewal with value True to update the cache manually.
• Cache Entry Hash: the hash code representing the input context for the cache entry. This is used to later match cache entries to the correct input context. The hashcode is created from the profile name, and the fields that were added as Input Context in the caching settings of the method.
• ValidUntil: the expiration date of the cache entry that is created, in local system time, same timezone as the Timestamp.
• Includes Merged Extensions: flag indicating if extensions were merged and included in the cache entry. This can only happen if the method has extensions, and the extensions themselves are also cached. Refer to Output Caching on Methods for details on caching in combination with extensions.

It is possible to see some duplicates cache writes in this report, this is by design: if the method is executed multiple times at the same time while there is no caching entries yet, none of the calls will find a cache entry. As a result, each call will create a new entry. Future reads from the cache will only use the entry with the most lifetime. The duplicates will get no usages, will not be automatically refreshed, and will be cleaned up once expired.

Storing cache entries is done asynchronously in order not to impact performance and can have a delay of 5 seconds at most. Each line in the report represents when the entry was queued to be added.

Report Extraction

The report results can serve as a basis for further analysis, for example by importing the data into an Excel document and applying some additional filtering on the records. However, the manual execution of each reporting method, and exporting and importing again into another application can be quite tedious. To improve this, an extra method called Export Reports To File has been added to automate some parts of the process, mainly the execution and extraction of the data.

Using this method is simple: provide some configuration input values like a folder to store the extracted reports, how long each report should remain available, etc, and most important of all, which reports must be run and extracted.

The end result of this method is a ZIP file containing all reporting results as separate files in either TSV (tab separated values) or Excel format. Also, the method is developed in such a way it can be used as a method job and scheduled to run at predefined times.

Input Configuration

To do its job properly, several fields must be provided at run-time.

• Reports Storage Path: here a full directory path must be given so that the method know where to store the report ZIP archives. If the folder doesn't exist, the method will attempt to create it and otherwise the execution will fail. Default value = %OMETA_INSTALL_ROOT%\Log\BAM Reports
• Retention Period In Days: as it is very likely that the method will be run as a job in the background, after a while a number of reporting archives can be present in the Reports Storage Path. To avoid using too much disk space, the number of archives can be limited based on a retention period the files can remain in the folder. Older files will be removed automatically. Default value = 7
• Data Set Time Range In Hours: each reporting method requires a time range to limit the data set to search through. To allow the export method to run as a job, the end timestamp of that date range is implicitly set at the time of starting the export run. With the value in this field, the beginning of the date range can be calculated. Default value = 24
• Report Methods Profile: all reporting method require a profile to get executed and that is not the same one as the export method needs to run. Each reporting method is an ODBC method. To let the export method use the right profile for the reporting methods, provide a name of an existing ODBC profile referring to the BAM database. Default value = BAM ODBC
• Report Export Type: file type to use for the different generated reports, either text or Excel files are possible. Default value = TSV (= Tab Separated Values)

Note

If needed, a separate profile can be configured for a single reporting method. Refer to paragraph Profile Override for more information.

Report Selection

Selecting which reports to include in the report ZIP archive, is simple: just select the one's that are needed. Limiting the number of reports will limit the time needed to run the full extraction process and makes the final archive smaller, saving on used disk space.

For ease of use, most reports in the export method are already enabled by default for inclusion in the ZIP archive. Those are the following:

• Report BCA Health Reports
• Report BCM Startups
• Report Data Model Excess Load Times
• Report DCS Case Saving Times
• Report Interface Kills Memory Exceeded
• Report Interface Startups
• Report Method Execution Times
• Report Occurred Deadlocks
• Report Occurred Errors
• Report Occurred Time Outs
• Report BCM Health Reports
• Report BCM Slot Requests
• Report Interface Requests
• Report Interrupted Methods
• Report Realtime Notification Durations
• Report Caching Reads
• Report Caching Writes

Not all reporting methods are available for export. The following are excluded:

• Get Full DCS Actions List By Case Id: this method requires VERBOSE (= tracing) logging and it is strongly advised NOT to enable that setting on production environments for normal operation, this method will not extract a lot of data.
• Get Method Execution Times By Template: there is an input data extension added and configuring the profile for that extension method is difficult to do from the export method's point of view.

Some reports may need additional input values:

• Message and Component: needed by the report Report Logging By Message And Component. By default both fields are empty.

Keep in mind: if these additional input values aren't defined, Export Reports To File will obviously pass no context values on to the reporting methods that need them.

Profile Override

In case it would be needed to run a reporting method on a different profile that the general one configured in the Report Methods Profile field, there is a simple way to override the profile value for that particular reporting method.

Note

Keep in mind that this override is only possible when the method Export Reports To File is configured in a method job because being a system method, it is not possible just to add extra input fields to the method itself.

For example, the method Get BCA Health Reports needs to run on a different BAM ODBC profile, do the following steps:

1. Make sure the method Export Reports To File is defined as a method job.
2. Within the method job, add the context (input) field Report BCA Health Reports so that it can be selected for extraction. Override the context value to select it.
3. Add an additional context field with the name Report BCA Health Reports Profile. In that field, provide the separate ODBC profile to use for that reporting method.

Repeat the steps 2 and 3 for each reporting method needed, just add the suffix ' Profile' to the report selection input field name to enable the override of the profile name.

Report File Format

By default all reports are written to the ZIP archive as Tab Separated Values (TSV) text files. Usually those reports are imported into Excel for further analysis of the data. Therefor an extra file format is added and reports can be written directly to Excel files.

When calling the extraction method, select the value Excel for the input Report Export Type field.

Note

When defining a method job, use the following values for the input field Report Export Type:

• tsv: Tab Separated Values
• excel: Excel format.

Support Methods

Not all methods in the Ometa.BAM.LogAnalysis system object are reporting methods. Some are support methods used as data extensions to the reporting methods.

Note

Basically, these methods are not created for separate use in any solution. As a result, their behaviour is only guaranteed within the reporting methods, and that may change if the reporting methods need to be adapted in future framework releases.

Method Retrieve All Profiles By Template

Returns all available profiles in a single field, that are linked to the provided list of templates.