Monitor Database

Moogsoft Onprem features the ability to print the current state of the database pool in both Moogfarmd and Apache Tomcat. You can use this information 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 ha_cntl utility triggers logging to the Moogfarmd log file, for example /var/log/moogsoft/MOO.moog_farmd.log. An example log entry in a performant system is as follows:

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.|+

The ha_cntl utility 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 shows 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 the system will function normally.

You can use the following bash script to automatically gather database pool 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

See HA Control Utility Command Reference for more information on the utility.