System Log

System logs contain standard information that identifies day-to-day processing. They are organized into logical sections.

Message Identification Values

Each message line begins with standard information that provides orientation for where and when the message occurred, including the logging level, process and thread IDs, date and time, and the MATRIXX process that generated the message.

The following example shows typical identification values located at the start of each message:

LM_INFO [transaction_server_1]

Where:

LM_INFO is the log level set for the Log Manager. The log level starts the beginning of each message. The other log levels are: LM_CRIT, LM_WARN, LM_INFO, LM_DEBUG, and LM_TRACE
[transaction_server_1] is the MATRIXX Engine component generating the message. In this case, the Transaction Server is running on server 1.

Standard Header Messages

The first several messages in a log file form the log header information and have information about the current logging configuration.

The following example shows the standard MATRIXX header messages:

LM_INFO  [transaction_server_1] | LogManager::readConfig(), mtx_config.xml: log file name = mtx_debug.log
LM_INFO  [transaction_server_1] | LogManager::readConfig(), mtx_config.xml: log level = info
LM_INFO  [transaction_server_1] | LogManager::readConfig(), mtx_config.xml: syslog log level = off
LM_INFO  [transaction_server_1] | LogManager::readConfig(), mtx_config.xml: syslog facility = local0
LM_INFO  [transaction_server_1] | LogManager::readConfig(), mtx_config.xml: log config update filename = log_update.cfg

Start Up Messages

The messages that follow the header information are generated for all system start-up operations. They include messages that occur when the MATRIXX Engine processes, messages, and database objects are first initialized in the system.

The following example shows a start-up message for the coordinator_sender_task:

LM_INFO [transaction_server_1] | ProcessStatus::start: starting task TXN1-CoordinatorsSender:coordinators_sender_task
LM_INFO [transaction_server_1] | TXN1-CoordinatorsSender:coordinators_sender_task:Task::start: TaskStatus is now 'STARTING'

Configuration Messages

The messages that follow the start up messages are generated for all MATRIXX processes. They include configuration information that is retrieved from the mtx_config.xml configuration file during start-up and cached in the configuration container associated with each server. All configuration information is read from the same configuration file, so the global configuration information, such as container description and database configuration, that is cached for all servers is the same. Then, each MATRIXX process reads its own server-specific configuration. For example, transaction_server_1 reads the information inside the <transaction_server id="1"> configuration in additional to the global configuration.

The following example shows configuration messages for the Charging Server's cache of the SubscriberIdAllocation container:

LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.BalanceIdList.datatype = unsigned int64
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.BalanceIdList.list = 1
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.BalanceIdQuantity.datatype = unsigned int32
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.SubscriberIdList.datatype = unsigned int64
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.SubscriberIdList.list = 1
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.SubscriberIdQuantity.datatype = unsigned int32
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.WalletIdList.datatype = unsigned int64
LM_INFO [charging_server_1] | Config NameValueMap: container.SubscriberIdAllocation.field.WalletIdList.list = 1

Latency Data

When MATRIXX Engine stops, latency statistics are written to the system log. The statistics begin recording when MATRIXX Engine starts. The latencies are recorded in buckets that span 1000 microseconds. Bucket 1 counts all packets that took 0–1000 microseconds to process, bucket 2 counts all packets that took 1000–2000 microseconds to process, and so on.

The following example shows Diameter Gateway and the Charging Server latency statistics written to the system log. Diameter Gateway latencies are measured from the time a message is received from the network to the time it is sent back to the network. Charging Server latency statistics are measured from the time the message is received by the Charging Server to the time it is returned to the Diameter Gateway. Both set of statistics include processing by the Transaction Server.

LM_INFO [diameter_gateway_1] | DiameterIO:diameter_sender_task: Latency bucket 0 (0 <= x < 1000 micros) -- 49 messages
LM_INFO  [diameter_gateway_1] | DiameterIO:diameter_sender_task: Latency bucket 1 (1000 <= x < 2000 micros) -- 7012 messages
LM_INFO  [diameter_gateway_1] | DiameterIO:diameter_sender_task: Latency bucket 2 (2000 <= x < 3000 micros) -- 3944 messages
LM_INFO  [diameter_gateway_1] | DiameterIO:diameter_sender_task: Latency bucket 3 (3000 <= x < 4000 micros) -- 4143 messages
LM_INFO  [charging_server_1] | CHRG-Response:response_task: Latency bucket 0 (0 <= x < 1000 micros) -- 60763 messages
LM_INFO  [charging_server_1] | CHRG-Response:response_task: Latency bucket 1 (1000 <= x < 2000 micros) -- 16903 messages
LM_INFO  [charging_server_1] | CHRG-Response:response_task: Latency bucket 2 (2000 <= x < 3000 micros) -- 437 messages
LM_INFO  [charging_server_1] | CHRG-Response:response_task: Latency results: max latency of 98334 micros detected in 2

Latencies caused by a Mobile Application Part (MAP) callout, call initiation, or Pay Now operation are not included in latency calculations that produce messages in the system log. To cause these relatively large latencies to be reported, set original_latency_log_trigger_in_millis in a sed.extra file. For example, to cause logging of latencies exceeding five seconds, add the following:

<original_latency_log_trigger_in_millis>5000</original_latency_log_trigger_in_millis>

A setting of 0 disables this feature.

Gateway Connection

The Diameter Gateway logs connection (open and close) diagnostic messages to facilitate diameter health monitoring. The following example shows Diameter Gateway connection states written to the system log:

LM_INFO [diameter_gateway_52] | DiameterIO:diameter_sender_task:01:TCPOutputHandler:open: socket options for addr=localhost:3868: [task IO size 65536] SO_SNDBUF 131072, TCP_NODELAY 0, TCP_CORK 0
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_receiver_task:01:TCPInputHandler::closeSocket: connectionData_ before: [0]=27 [1]=28 [2]=29 [3]=30 [4]=32
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_receiver_task:01:TCPInputHandler::closeSocket: closing the input socket [INPUT CHANNEL]. addr=localhost:3868, fd=32
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_receiver_task:01:TCPInputHandler::closeSocket: connectionData_.size before=5, after=4. addr=localhost:3868, fd=32, connectionData_: [0]=27 [1]=28 [2]=29 [3]=30
LM_INFO [charging_server_52] | ResponseTask::getAndResetMsgStats: msgCnt=993012, prevMsgCnt=988028, microsPerMsg=200
LM_INFO [charging_server_52] | EnrichmentTask::handleInput: receivedBuf: queueIndex=0, msgCnt=2993038, prevMsgCnt=2988043, prevMicrosPerMsg=200, microsPerMsg=200, deltaMicrosPerMsg=0
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_receiver_task:01:TCPInputHandler::handle_input: Accept OK. addr=localhost:3868, fd=32
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_sender_task:01:IOSenderTask::openConnection: establishing a connection to localhost:3868, socketFd=28
LM_INFO [diameter_gateway_52] | DiameterIO:diameter_sender_task:01:TCPOutputHandler:open: using established socket to addr=localhost:3868, fd=32