Determining tec_gateway and state based correlation performance

Set up the tec_gateway process for tracing by updating the .tec_gateway_diag_config file with the following parameters:

#
#

Highest_level trace2

Truncate_on_restart true


# tec_gateway
#############

tec_gateway Highest_level trace2
tec_gateway Gw_Send trace2 /tmp/tec_gateway
tec_gateway State_Correlator trace2 /tmp/tec_gateway

Stop the tec_gateway process

Use the following template as a guide to determine how long this processing takes:

Aug 23 16:03:06.738005 tec_gateway[25222] TR2 gw_send_event.c:736: Entering send_event -
location=@EventServer
<on newline>message=
Su_Success;hostname=test_hostname;sub_origin=test_hostname;date='Aug 23 16:02:52';origin=1.1.1.1;msg='su success: root->db2inst1';sub_source=su;from_user=root;to_user=db2inst1;on_tty=/dev/pts/3;END
_

EVENT RECEIVED BY TEC_GATEWAY
Aug 2316:03:06.738304 tec_gateway[25222] TR2 gw_send_event.c: 1528:Entering get_handle location=@EventServer

Aug 23 16:03:06.738506 tec_gateway[25222] TR2 gw_send_event.c:1576: pNode == NULL
Aug 23 16:03:06.844981 tec_gateway[25222] TR2 gw_send_event.c:1625: create_handle errno=0
Aug 23 16:03:06.845378 tec_gateway[25222] TR2 gw_send_event.c:1643: restore location
Aug 23 16:03:06.845593 tec_gateway[25222] TR2 gw_send_event.c:1683: bufpath=/etc/Tivoli/tec/tec_gateway_sce.cache retry_interval=120
Aug 23 16:03:06.849553 tec_gateway[25222] TR2 gw_send_event.c:2016: Entering router location=@EventServer port=0
Aug 23 16:03:06.850082 tec_gateway[25222] TR2 gw_send_event.c:2028: buff_size=0
Aug 23 16:03:06.850260 tec_gateway[25222] TR2 gw_send_event.c:2037: TRUE emptyQ 1 _and_ buff_size 0 == 0
Aug 23 16:03:06.850425 tec_gateway[25222] TR2 gw_send_event.c:2039: FALSE timer_id -1 >= 0
Aug 23 16:03:06.850582 tec_gateway[25222] TR2 gw_send_event.c:2041: FALSE retry timer_id -1 >= 0
Aug 23 16:03:06.850752 tec_gateway[25222] TR2 gw_send_event.c:2055: router location=@EventServer sleeping...
Aug 23 16:03:07.121818 tec_gateway[25222] TR2 gw_send_event.c:1722: Leaving get_handle
Aug 23 16:03:07.122148 tec_gateway[25222] TR2 gw_send_event.c:903: Entering queue_event

EVENT SENT TO SBCE
Aug 23 16:03:07.122323 tec_gateway[25222] TR2 gw_send_event.c:932: Sending event to state correlation

Aug 23 16:03:07.122500 tec_gateway[25222] TR2 gw_state_correlator.c:892: Entering correlate_event serverInfo=@EventServer
Aug 23 16:03:07.122677 tec_gateway[25222] TR2 gw_state_correlator.c:907: sending msg = <12:@EventServer>Su_Success;hostname=test_hostname;sub_origin=test_hostname;date='Aug 23 16:02:52';origin=1.1.1.1;msg='su success: root->db2inst1';sub_source=su;from_user=root;to_user=db2inst1;on_tty=/dev/pts/3;END_ - 206
Aug 23 16:03:07.122836 tec_gateway[25222] TR2 gw_state_correlator.c:507: Entering send_event
Aug 23 16:03:07.123189 tec_gateway[25222] TR2 gw_state_correlator.c:538: Event sent OK
Aug 23 16:03:07.123498 tec_gateway[25222] TR2 gw_state_correlator.c:542: Wait for state correlation ack
Aug 23 16:03:14.756625 tec_gateway[25222] TR2 gw_state_correlator.c:263: Receiving event
Aug 23 16:03:14.756992 tec_gateway[25222] TR2 gw_state_correlator.c:271: Processing event
Aug 23 16:03:14.757167 tec_gateway[25222] TR2 gw_state_correlator.c:188: Entering process_event
Aug 23 16:03:14.757336 tec_gateway[25222] TR2 gw_state_correlator.c:198: aug name len=12
Aug 23 16:03:14.757499 tec_gateway[25222] TR2 gw_state_correlator.c:208: serverInfo=@EventServer

EVENT LEAVES SBCE
Aug 23 16:03:14.757655 tec_gateway[25222] TR2 gw_state_correlator.c:214: Processing event - Su_Success;to_user=db2inst1;msg='su success: root->db2inst1';date='Aug 23 16:02:52';on_tty=/dev/pts/3;from_user=root;sub_origin=test_hostname;hostname=test_hostname;origin=1.1.1.1;sub_source=su;END_


EVENT RECEIVED BY TEC_GATEWAY FROM SBCE
Aug 23 16:03:14.757819 tec_gateway[25222] TR2 gw_send_event.c:1528: Entering get_handle location=@EventServer

Aug 23 16:03:14.758012 tec_gateway[25222] TR2 gw_send_event.c:1722: Leaving get_handle
Aug 23 16:03:14.758179 tec_gateway[25222] TR2 gw_send_event.c:827: Entering queue_processed_event
Aug 23 16:03:14.758344 tec_gateway[25222] TR2 gw_send_event.c:837: location=@EventServer
<on newline>normalizedMsg=
Su_Success;to_user=db2inst1;msg='su success: root->db2inst1';date='Aug 23 16:02:52';on_tty=/dev/pts/3;from_user=root;sub_origin=test_hostname;hostname=test_hostname;origin=1.1.1.1;sub_source=su;END
_
Aug 23 16:03:14.758508 tec_gateway[25222] TR2 gw_send_event.c:2421: Entering evQueueNQEv - event length = 189
Aug 23 16:03:14.758791 tec_gateway[25222] TR2 gw_send_event.c:2473: counting how many events are in the message
Aug 23 16:03:14.759028 tec_gateway[25222] TR2 gw_send_event.c:2480: Leaving evQueueNQEv queuedEvents=1
Aug 23 16:03:14.759202 tec_gateway[25222] TR2 gw_send_event.c:843: Set forwarding timer.
<on newline>normalizedMsg=
Su_Success;to_user=db2inst1;msg='su success: root->db2inst1';date='Aug 23 16:02:52';on_tty=/dev/pts/3;from_user=root;sub_origin=test_hostname;hostname=test_hostname;origin=1.1.1.1;sub_source=su;END
_
Aug 23 16:03:14.759366 tec_gateway[25222] TR2 gw_send_event.c:2258: Entering set_forwarding_timer
Aug 23 16:03:14.759525 tec_gateway[25222] TR2 gw_send_event.c:2263: Server info does not have a timer.
Aug 23 16:03:14.759690 tec_gateway[25222] TR2 gw_send_event.c:2275: Establishing new timer.
Aug 23 16:03:14.759918 tec_gateway[25222] TR1 gw_send_event.c:2281: Established new timer timer_id=262
Aug 23 16:03:14.760093 tec_gateway[25222] TR2 gw_send_event.c:2302: Leaving set_forwarding_timer timer_id=262
Aug 23 16:03:14.760254 tec_gateway[25222] TR2 gw_send_event.c:854: Leaving queue_processed_event rc=0
Aug 23 16:03:14.760524 tec_gateway[25222] TR2 gw_state_correlator.c:221: Leaving process_event - return 1
Aug 23 16:03:14.760713 tec_gateway[25222] TR2 gw_state_correlator.c:274: Sending ACK
Aug 23 16:03:14.762377 tec_gateway[25222] TR2 gw_state_correlator.c:568: Receive ACK
Aug 23 16:03:14.762624 tec_gateway[25222] TR2 gw_state_correlator.c:578: Leaving send_event - return 1
Aug 23 16:03:14.763495 tec_gateway[25222] TR2 gw_state_correlator.c:935: Leaving correlate_event rc=1
Aug 23 16:03:14.763710 tec_gateway[25222] TR2 gw_send_event.c:937: Leaving queue_event rc=0

TEC_GATEWAY SENDS EVENT TO TEC SERVER
Aug 23 16:03:14.763873 tec_gateway[25222] TR2 gw_send_event.c:765: Leaving send_event