IBM Tivoli Netcool/OMNIbus, Version 7.4

Collect statistical information about triggers

Timing information about triggers, including the number of times the trigger has been raised and the number of times the trigger has fired, are saved to the catalog.trigger_stats table.

To collect trigger statistics:

Ensure that the Auto.Enabled property of the ObjectServer is set to TRUE. This is the default setting, and is used to enable the automation system.
Use the Auto.StatsInterval property to control the frequency at which the automation system collects and stores statistical information to the catalog.trigger_stats table. A default interval of 60 seconds is used if you do not change this value.
Ensure that the trigger_stat_reports trigger group and the trigger_stats_report trigger are enabled.

You can use Netcool/OMNIbus Administrator to view details that are recorded in the catalog.trigger_stats table. From the Netcool/OMNIbus Administrator window, select the System menu button and then click Databases. You can use the Data View tab on the Databases, Tables and Columns pane to view table data, and use the Column Definitions tab to view detailed information about the columns in the table.

Trigger statistics are also logged to the file $NCHOME/omnibus/log/servername_trigger_stats.logn, where servername represents the ObjectServer name and n is a number. The trigger statistics log file shows the amount of time that each trigger has used in the last profiling period. You can use this log file for automation debugging, and to determine which triggers are slow due to slow-running SQL queries. Sample output recorded in a trigger statistics log file is as follows:

[1]  Mon Oct 12 18:03:56 2009: Trigger Profile Report
[2]  Mon Oct 12 18:03:56 2009: Trigger Group 'compatibility_triggers'
[3]  Mon Oct 12 18:03:56 2009: Trigger Group 'system_watch'
[4]  Mon Oct 12 18:03:56 2009:     Trigger time for 'system_watch_shutdown': 0.000000s
[5]  Mon Oct 12 18:03:56 2009:     Trigger time for 'system_watch_startup': 0.000000s
[6]  Mon Oct 12 18:03:56 2009: Trigger Group 'sae'
[7]  Mon Oct 12 18:03:56 2009:     Trigger time for 'update_service_affecting_events': 0.006790s
[8]  Mon Oct 12 18:03:56 2009: Trigger Group 'default_triggers'
[9]  Mon Oct 12 18:03:56 2009:     Trigger time for 'deduplication': 0.341918s
[10] Mon Oct 12 18:03:56 2009:     Trigger time for 'deduplication_eval': 0.092659s
[11] Mon Oct 12 18:03:56 2009:     Trigger time for 'service_update': 0.000000s
[12] Mon Oct 12 18:03:56 2009:     Trigger time for 'clean_journal_table': 0.000172s
[13] Mon Oct 12 18:03:56 2009:     Trigger time for 'service_insert': 0.000000s
[14] Mon Oct 12 18:03:56 2009:     Trigger time for 'service_reinsert': 0.000000s
[15] Mon Oct 12 18:03:56 2009:     Trigger time for 'clean_details_table': 0.000083s
[16] Mon Oct 12 18:03:56 2009:     Trigger time for 'state_change': 0.075508s
[17] Mon Oct 12 18:03:56 2009:     Trigger time for 'deduplication_copy': 0.022087s
[18] Mon Oct 12 18:03:56 2009:     Trigger time for 'new_row': 0.002637s
[19] Mon Oct 12 18:03:56 2009:     Trigger time for 'deduplicate_details': 0.000000s
[20] Mon Oct 12 18:03:56 2009: Trigger Group 'connection_watch'
[21] Mon Oct 12 18:03:56 2009:     Trigger time for 'connection_watch_connect': 0.000000s
[22] Mon Oct 12 18:03:56 2009:     Trigger time for 'connection_watch_disconnect': 0.000000s
[23] Mon Oct 12 18:03:56 2009: Trigger Group 'primary_only'
[24] Mon Oct 12 18:03:56 2009:     Trigger time for 'generic_clear': 5.879707s
[25] Mon Oct 12 18:03:56 2009:     Trigger time for 'expire': 0.008233s
[26] Mon Oct 12 18:03:56 2009:     Trigger time for 'delete_clears': 0.007219s
[27] Mon Oct 12 18:03:56 2009:     Trigger time for 'enrich_and_correlate': 23.007219s
[28] Mon Oct 12 18:03:56 2009: Trigger Group 'security_watch'
[29] Mon Oct 12 18:03:56 2009:     Trigger time for 'disable_user': 0.000000s
[30] Mon Oct 12 18:03:56 2009:     Trigger time for 'reset_user': 0.000000s
[31] Mon Oct 12 18:03:56 2009:     Trigger time for 'security_watch_security_failure': 0.000000s
[32] Mon Oct 12 18:03:56 2009: Trigger Group 'profiler_triggers'
[33] Mon Oct 12 18:03:56 2009:     Trigger time for 'profiler_group_report': 0.065094s
[34] Mon Oct 12 18:03:56 2009:     Trigger time for 'profiler_report': 0.087705s
[35] Mon Oct 12 18:03:56 2009:     Trigger time for 'profiler_toggle': 0.000000s
[36] Mon Oct 12 18:03:56 2009: Trigger Group 'trigger_stat_reports'
[37] Mon Oct 12 18:03:56 2009:     Trigger time for 'trigger_stats_report': 0.198813s
[38] Mon Oct 12 18:03:56 2009: Trigger Group 'iduc_triggers'
[39] Mon Oct 12 18:03:56 2009:     Trigger time for 'disconnect_iduc_missed': 0.000000s
[40] Mon Oct 12 18:03:56 2009:     Trigger time for 'iduc_stats_update': 0.000949s
[41] Mon Oct 12 18:03:56 2009:     Trigger time for 'iduc_messages_tblclean': 0.000089s
[42] Mon Oct 12 18:03:56 2009:     Trigger time for 'deduplicate_iduc_stats': 0.000000s
[43] Mon Oct 12 18:03:56 2009:     Trigger time for 'iduc_stats_insert': 0.000000s
[44] Mon Oct 12 18:03:56 2009: Trigger Group 'automatic_backup_system'
[45] Mon Oct 12 18:03:56 2009:     Trigger time for 'backup_succeeded': 0.000000s
[46] Mon Oct 12 18:03:56 2009:     Trigger time for 'backup_failed': 0.000000s
[47] Mon Oct 12 18:03:56 2009:     Trigger time for 'backup_state_integrity': 0.000000s
[48] Mon Oct 12 18:03:56 2009: Trigger Group 'gateway_triggers'
[49] Mon Oct 12 18:03:56 2009:     Trigger time for 'resync_finished': 0.000000s
[50] Mon Oct 12 18:03:56 2009: Time for all triggers in report period (60s): 29.789663s

The line numbers are included in the preceding output to help describe the entries:

Line [1]: Indicates the start of the report and shows the timestamp for when the report was produced.
Line [2]: Shows that the report is broken down by trigger group. In this case, the compatibility_triggers trigger group does not contain any enabled triggers.
Line [3]: Shows system_watch as the first trigger group that contains enabled triggers.
Line [4]: Shows the name of the trigger, and the amount of time (in seconds) used by the trigger in the last profiling period.
Line [27]: Indicates an excessive amount of time for the trigger. If this is a regular occurrence, the trigger would need to be investigated further. For example, the following questions could apply: Are there table scans in a database trigger? Are nested scans being used? Could an index be used to reduce scans? Is the time directly related to the number of events that the system is dealing with? Does the trigger use an EVALUATE clause that could be replaced by a FOR EACH clause operating directly on the table with the ACTION clause?
Line [50]: Shows the summary line as the last entry in the report. This line shows the time in seconds since the last report was run, and the total amount of time used by the triggers in the reporting period. In this example, 29 seconds out of 60 seconds is a high percentage, so further investigation might be necessary to determine the cause, particularly if this value is a regular occurrence.

Analyze the trigger statistics in the log file and database table to determine whether any workload is causing a degradation in performance:

If a trigger is identified as using the majority of the granularity period, investigate the cause.
Review your custom ObjectServer automations to assess their efficiency and to reduce the workload on the ObjectServer.
Make sure that trigger execution time is kept to a minimum, because no other writes can occur while a trigger is being executed.

Tip: When troubleshooting performance, the profile log file and trigger statistics log file are the first place to investigate. Generally, if the total combined time for both clients and triggers is consistently over 60 seconds (the default granularity period), some action needs to be taken. Various operating system metrics can also be useful in identifying whether a system is under stress. The key metrics are the CPU utilization and the process size of the Tivoli Netcool/OMNIbus processes.