Monitor and Troubleshoot Moogsoft AIOps

Navigate to System Settings > Self Monitoring > Processing Metrics to see a breakdown of the current state of the system based on the metrics received from the running components.

Good performance means LAMs are consuming and publishing events without problem as indicated by:

Additionally, Moogfarmd is consuming and processing events successfully as indicated by all of:

The above should lead to a stable low Current Maximum Event Processing Time depending on the complexity of the system.

Marginal or Bad performance means LAMs are not consuming and publishing events at the rate at which they receive them, as indicated by:

Additionally, Moogfarmd is not consuming and processing events in a timely fashion as indicated by some or all of:

The above will likely lead to an unstable high Current Maximum Event Processing Time depending on the complexity of the system.

See Self Monitoring for more detail.

The getSystemStatus endpoint returns useful information about running processes within the system. For example:

curl -u graze:graze -k "https://localhost/graze/v1/getSystemStatus"

See Graze API for more detail.

Moogfarmd writes detailed health information in JSON format to its log file once a minute. Information falls into five logical blocks:

Example output:

WARN : [HLog   ][20180510 20:39:55.538 +0100] [CFarmdHealth.java]:533 +|{"garbage_collection":{"total_collections_time":12827,"last_minute_collections":0,"last_minute_collections_time":0,"total_collections":1244},"current_state":{"pending_changed_situations":0,"total_in_memory_situations":4764,"situations_for_resolution":0,"event_processing_metric":0.047474747474747475,"message_queues":{"AlertBuilder":0,"TeamsMgr":0,"Housekeeper":0,"Indexer":0,"bus_thread_pool":0,"Cookbook3":0,"Cookbook1":0,"SituationMgr":0,"SituationRootCause":0,"Cookbook2":0},"in_memory_entropies":452283,"cookbook_resolution_queue":0,"total_in_memory_priority_situations":0,"active_async_tasks_count":0},"interval_totals":{"created_events":1782,"created_priority_situations":0,"created_external_situations":0,"created_situations":10,"messages_processed":{"TeamsMgr":182,"Housekeeper":0,"AlertBuilder":1782,"Indexer":2082,"Cookbook3":1782,"SituationRootCause":172,"Cookbook1":1782,"SituationMgr":172,"Cookbook2":1782},"alerts_added_to_priority_situations":0,"alerts_added_to_situations":111,"situation_db_update_failure":0},"JVM_memory":{"heap_used":1843627096,"heap_committed":3007840256,"heap_init":2113929216,"nonheap_committed":66912256,"heap_max":28631367680,"nonheap_init":2555904,"nonheap_used":64159032,"nonheap_max":-1},"totals":{"created_events":453252,"created_priority_situations":0,"created_external_situations":0,"created_situations":4764,"alerts_added_to_priority_situations":0,"alerts_added_to_situations":36020,"situation_db_update_failure":0}}|+

The message_queues block contains string values and queue limits. "-" represents an unlimited queue. An example message_queues block is as follows:

"message_queues":{"AlertBuilder":"0/-","Cookbook":"0/-","Housekeeper":"0/-","Indexer":"0/-","bus_thread_pool":"0/-","SituationMgr":"0/-"}

In a healthy system that is processing data:

Tomcat writes counter information from each of the main servlets to its catalina.out once a minute.

Example output:

WARN : [Thread-][20180510 20:57:05.501 +0100] [CReporterThread.java]:136 +|MoogPoller read [16722] MooMs messages in the last [60] seconds.|+
WARN : [Thread-][20180510 20:57:07.169 +0100] [CReporterThread.java]:136 +|Graze handled [55] requests in the last [60] seconds.|+
WARN : [Thread-][20180510 20:57:10.181 +0100] [CReporterThread.java]:136 +|MoogSvr handled [86] requests in the last [60] seconds.|+
WARN : [Thread-][20180510 20:58:03.197 +0100] [CReporterThread.java]:136 +|Situations similarity component calculated similarities for [264] situations in the last [60] seconds.|+

The counters are:

In a healthy system that is processing data:

Moogsoft AIOps features a capability to print out the current state of the DBPool in both Moogfarmd and Tomcat. This can be very useful to diagnose problems with slow event processing or UI response.

To trigger logging, run the ha_cntl utility and pass the cluster name using the -i argument. For example:

ha_cntl -i MOO 
This will perform task "diagnostics" all groups within the [MOO] cluster.
Diagnostics results will be in the target process log file.
Are you sure you want to continue? (y/N)

The utility triggers logging to /var/log/moogsoft/moogfarmd.log. For example in a performant system:

WARN : [pool-1-][20180511 10:06:07.690 +0100] [CDbPool.java]:792 +|[farmd] DATABASE POOL DIAGNOSTICS:|+
WARN : [pool-1-][20180511 10:06:07.690 +0100] [CDbPool.java]:793 +|[farmd] Pool created at [20180510 17:54:48.911 +0100].|+
WARN : [pool-1-][20180511 10:06:07.690 +0100] [CDbPool.java]:797 +|[farmd] [2] invalid connections have been removed during the lifetime of the pool.|+
WARN : [pool-1-][20180511 10:06:07.690 +0100] [CDbPool.java]:833 +|[farmd] Pool size is [10] with [10] available connections and [0] busy.|+

It also triggers logging to /usr/share/apache-tomcat/logs/catalina.out. For example:

WARN : [0:MooMS][20180511 10:06:07.690 +0100] [CDbPool.java]:792 +|[SituationSimilarity] DATABASE POOL DIAGNOSTICS:|+
WARN : [0:MooMS][20180511 10:06:07.690 +0100] [CDbPool.java]:793 +|[SituationSimilarity] Pool created at [20180510 17:55:04.262 +0100].|+
WARN : [3:MooMS][20180511 10:06:07.690 +0100] [CDbPool.java]:792 +|[MoogPoller] DATABASE POOL DIAGNOSTICS:|+
WARN : [3:MooMS][20180511 10:06:07.690 +0100] [CDbPool.java]:793 +|[MoogPoller] Pool created at [20180510 17:55:01.990 +0100].|+
WARN : [0:MooMS][20180511 10:06:07.690 +0100] [CDbPool.java]:833 +|[SituationSimilarity] Pool size is [5] with [5] available connections and [0] busy.|+
WARN : [3:MooMS][20180511 10:06:07.691 +0100] [CDbPool.java]:833 +|[MoogPoller] Pool size is [10] with [10] available connections and [0] busy.|+
WARN : [1:MooMS][20180511 10:06:07.693 +0100] [CDbPool.java]:792 +|[ToolRunner] DATABASE POOL DIAGNOSTICS:|+
WARN : [1:MooMS][20180511 10:06:07.694 +0100] [CDbPool.java]:793 +|[ToolRunner] Pool created at [20180510 17:55:00.183 +0100].|+
WARN : [1:MooMS][20180511 10:06:07.694 +0100] [CDbPool.java]:792 +|[MoogSvr : priority] DATABASE POOL DIAGNOSTICS:|+
WARN : [1:MooMS][20180511 10:06:07.694 +0100] [CDbPool.java]:833 +|[ToolRunner] Pool size is [5] with [5] available connections and [0] busy.|+
WARN : [1:MooMS][20180511 10:06:07.694 +0100] [CDbPool.java]:793 +|[MoogSvr : priority] Pool created at [20180510 17:54:56.800 +0100].|+
WARN : [1:MooMS][20180511 10:06:07.695 +0100] [CDbPool.java]:797 +|[MoogSvr : priority] [5] invalid connections have been removed during the lifetime of the pool.|+
WARN : [1:MooMS][20180511 10:06:07.695 +0100] [CDbPool.java]:833 +|[MoogSvr : priority] Pool size is [25] with [25] available connections and [0] busy.|+
WARN : [1:MooMS][20180511 10:06:07.695 +0100] [CDbPool.java]:792 +|[MoogSvr : normal priority] DATABASE POOL DIAGNOSTICS:|+
WARN : [1:MooMS][20180511 10:06:07.695 +0100] [CDbPool.java]:793 +|[MoogSvr : normal priority] Pool created at [20180510 17:54:56.877 +0100].|+
WARN : [1:MooMS][20180511 10:06:07.695 +0100] [CDbPool.java]:833 +|[MoogSvr : normal priority] Pool size is [50] with [50] available connections and [0] busy.|+

In both of these examples, the connections are "available" and none show as busy. However, in a busy system with flagging performance, the Moogfarmd log will show different results. In the example below, all connections are busy and have been held for a long time. This type of critical issue causes Moogfarmd to stop processing:

WARN : [pool-1-]20180309 16:49:30.031 +0000] [CDbPool.java]:827 +|[farmd] Pool size is [10] with [0] available connections and [10] busy.|+
WARN : [pool-1-][20180309 16:49:30.031 +0000] [CDbPool.java]:831 +|The busy connections are as follows:
1: Held by 5:SituationMgrLOGFILECOOKBOOK for 173603 milliseconds. Checked out at [CArchiveConfig.java]:283.
2: Held by 7:SituationMgrSYSLOGCOOKBOOK for 173574 milliseconds. Checked out at [CArchiveConfig.java]:283.
3: Held by 8:SituationMgrSYSLOGCOOKBOOK for 173658 milliseconds. Checked out at [CArchiveConfig.java]:283.
4: Held by 9:SituationMgrSYSLOGCOOKBOOK for 173477 milliseconds. Checked out at [CArchiveConfig.java]:283.
5: Held by 8:TeamsMgr for 173614 milliseconds. Checked out at [CArchiveConfig.java]:283.
6: Held by 4:SituationMgrSYSLOGCOOKBOOK for 173514 milliseconds. Checked out at [CArchiveConfig.java]:283.
7: Held by 5:PRC Request Assign - SituationRootCause for 173485 milliseconds. Checked out at [CArchiveConfig.java]:283.
8: Held by 2:SituationMgrSYSLOGCOOKBOOK for 173661 milliseconds. Checked out at [CArchiveConfig.java]:283.
9: Held by 6:SituationMgrSYSLOGCOOKBOOK for 173631 milliseconds. Checked out at [CArchiveConfig.java]:283.
10: Held by 6:TeamsMgr for 172661 milliseconds. Checked out at [CArchiveConfig.java]:283.|+

It is expected that occasionally some of the connections will be busy but as long as they are not held for long periods of time then the system will be functioning normally.

You can use the following bash script to automatically gather DBPool diagnostics:

#!/bin/bash

#Get the cluster name
CLUSTER=$($MOOGSOFT_HOME/bin/utils/moog_config_reader -k ha.cluster)

#Get the current line numbers of latest log lines
FARMLINES=$(wc -l /var/log/moogsoft/moogfarmd.log|awk '{print $1}')
TOMLINES=$(wc -l /usr/share/apache-tomcat/logs/catalina.out|awk '{print $1}')

#Run ha_cntl -i <cluster>
ha_cntl -i $CLUSTER -y > /dev/null

sleep 5

#Print the results
echo "moog_farmd:"
tail -n +$FARMLINES /var/log/moogsoft/moogfarmd.log|egrep "CDbPool|Held by"

echo "tomcat:"
tail -n +$TOMLINES /usr/share/apache-tomcat/logs/catalina.out|egrep "CDbPool|Held by"

To run the script, execute the following command:

./get_dbpool_diag.sh

Slow query logging captures long running queries that are impacting the database. You can enable the feature as follows:

The value of the long_query_time setting can also be adjusted up or down as suits.

RabbitMQ includes an admin UI that gives performance information about the message bus. By default this is accessible via http://<hostname>:15672 with credentials moogsoft/m00gs0ft. Check for the following scenarios:

See the RabbitMQ docs for information on how to use the admin UI.

MySQLTuner provides useful diagnostics and recommendations on MySQL settings. See MySQLTuner for more information.

To monitor the CPU and memory usage of the running components of a Moogsoft AIOps system, you can run the following script that offers simple CPU and memory monitoring of the RabbitMQ, Socket LAM, Moogfarmd, Tomcat and MySQL processes:

#!/bin/bash

SLEEPTIME=$1

f_return_metrics() {

        PROCPID=$1
        TOPOUTPUT=`top -p $PROCPID -n1 | tail -2 | head -1 |sed 's/[^ ]\+\s\(.*\)/\1/g'`
        PROCICPU=`echo $TOPOUTPUT| awk '{print $8}'`
        if [ "$PROCICPU" == "S" ]; then PROCICPU=`echo $TOPOUTPUT| awk '{print $9}'`;fi
        PROCPCPU=`ps -p $PROCPID -o pcpu|tail -1|awk '{print $1}'`
        PROCMEM=`ps -p $PROCPID -o rss|tail -1|awk '{print $1}'`
        echo $PROCICPU,$PROCPCPU,$PROCMEM

}

#Capture PIDs
RABBITPID=`ps -ef|grep beam|grep -v grep|awk '{print $2}'`
LAMPID=`ps -ef|grep socket_lam|grep java|grep -v grep|awk '{print $2}'`
MYSQLPID=`ps -ef|grep mysqld|grep -v mysqld_safe|grep -v grep|awk '{print $2}'`
TOMCATPID=`ps -ef|grep tomcat|grep java|grep -v grep|awk '{print $2}'`
FARMDPID=`ps -ef|grep moog_farmd|grep java|grep -v grep|awk '{print $2}'`

echo "DATE,TIME,RABBITICPU(%),RABBITPCPU(%),RABBITRSS(Kb),LAMICPU(%),LAMPCPU(%),LAMRSS(Kb),FARMDICPU(%),FARMDPCPU(%),FARMDRSS(Kb),TOMCATICPU(%),TOMCATPCPU(%),TOMCATRSS(Kb),MYSQLICPU(%),MYSQLPCPU(%),MYSQLRSS(Kb)"

while [ true ]; do

  DATENOW=`date +"%m-%d-%y"`
  TIMENOW=`date +"%T"`

  RABBITMEAS=$(f_return_metrics $RABBITPID)
  LAMMEAS=$(f_return_metrics $LAMPID)
  FARMDMEAS=$(f_return_metrics $FARMDPID)
  TOMCATMEAS=$(f_return_metrics $TOMCATPID)
  MYSQLMEAS=$(f_return_metrics $MYSQLPID)
  TOMCATMEAS=$(f_return_metrics $TOMCATPID)

  echo "$DATENOW,$TIMENOW,$RABBITMEAS,$LAMMEAS,$FARMDMEAS,$TOMCATMEAS,$MYSQLMEAS"

  sleep $SLEEPTIME

done

Example usage and output:

[root@ldev04 640]# ./perfmon.sh 5
DATE,TIME,RABBITICPU(%),RABBITPCPU(%),RABBITRSS(Kb),LAMICPU(%),LAMPCPU(%),LAMRSS(Kb),FARMDICPU(%),FARMDPCPU(%),FARMDRSS(Kb),TOMCATICPU(%),TOMCATPCPU(%),TOMCATRSS(Kb),MYSQLICPU(%),MYSQLPCPU(%),MYSQLRSS(Kb)
05-10-18,22:44:26,28.0,8.5,203068,2.0,1.0,557092,20.0,13.5,2853408,4.0,2.1,5680584,28.0,17.4,9657152
05-10-18,22:44:34,14.0,8.5,183492,4.0,1.0,557092,16.0,13.5,2850484,0.0,2.1,5680584,33.9,17.4,9657152
05-10-18,22:44:43,0.0,8.5,181072,0.0,1.0,557092,0.0,13.5,2850484,0.0,2.1,5680584,4.0,17.4,9658312
05-10-18,22:44:51,12.0,8.5,181040,0.0,1.0,557092,0.0,13.5,2850484,0.0,2.1,5680584,4.0,17.4,9658312
05-10-18,22:44:59,0.0,8.5,181040,0.0,1.0,557092,0.0,13.4,2850484,0.0,2.1,5680584,0.0,17.4,9658312

Notes:

If the system is showing signs of latency in alert or Situation creation then the problem is likely with Moogfarmd and/or the database. The following diagnostic steps will help you track down the cause:

grep "Resolve has been running for" /var/log/moogsoft/moogfarmd.log

DUMPFILE=/tmp/farmd-heapdump-$(date +%s).bin
sudo -u moogsoft jmap -dump:format=b,file=$DUMPFILE $(ps -ef|grep java|grep moog_farmd|awk '{print $2}')
bzip2 $DUMPFILE

If the system is showing signs of slow UI performance, such as long login times, spinning summary counters, or other, then the problem is likely with Tomcat and/or the database. The following diagnostic steps will help you track down the cause:

DUMPFILE=/tmp/tomcat-heapdump-$(date +%s).bin
sudo -u tomcat jmap -dump:format=b,file=$DUMPFILE $(ps -ef|grep java|grep tomcat|awk '{print $2}')
bzip2 $DUMPFILE