Logging

Logging is performed by the EMG log server which runs in the emgd process but in a separate thread. It implements a special log queue in order to minimize impact on EMG performance.

Log files

The log files are, by default located in the EMGDIR/log directory and there are different files for different logs:

Log fileDescription
generalServer log file where log entries with log level INFO or higher is written
debugServer log file where log entries with log level DEBUG and DEBUG2 is written
profilingThe time spent on each possibly time consuming operation. See full description below.
pdu.*Connector specific log file where all protocol operations will be logged
connector.*Connector specific log file where the EMG representation of operations and messages will be logged (mgp format)

There are two ways to change the location of the log files:

  1. Create a log file directory and make a symbolic link from EMGDIR/log to the new log file directory. This must be done while the server is stopped.
  2. It is also possible to set an environment variable EMGLOGDIR, before starting the server, pointing to the directory where the log files should be written.

Log levels

The log level determines how detailed the logging should be and can be set both for the server-wide logs and for the connector-specific logs using the LOGLEVEL keyword in the general or connector context.

When the server is started with the –debug or –debug2 option the log level is set to DEBUG or DEBUG2 and the log messages are also displayed on stdout. This can be useful for debugging purposes.

It is also possible to use log file rotation based on size in order to limit the maximum amount of disk space occupied by log files.

Format of log files

All log files contain a timestamp with a precision down to one microsec. It also contains a message text and, if relevant, message properties. The default format is similar to the syslog format and does not include year. The general keyword LOGYEAR changes the date format in the timestamp to YYYY-MM-DD.

Connector log file

The connector log file includes all events for a specifiec connector. Specifically all messages sent and received will show up in one of the connector log files. A message which passes through EMG will show up at least two times usually in different log files. One entry when message was received and one entry when message was sent. It is possible for the same message to occur more than twice in log files, for example if sending the message first failed and the a retry was made which was successful. It is possible to differ between final and non-final entries since only the final entries include the ENDSECS (95) and ENDMSECS (96) message options.

<timestamp> (<instance>) <event> <OK/ERR> [(<info>)] [<options>]
FieldDescription
timestampMandatory. Default format is MMM DD hh:mm:ss.mmm. If LOGYEAR is used format is YYYY-MM-DD hh:mm:ss.mmm.
instanceMandatory. Connector instance on which the event occurred.
eventMandatory. Type of event that has occurred. Can be of one the following values:CONNECT, DISCONNECT, LOGIN, LOGOUT, SEND, RECEIVE, REJECT, MAXFAIL, EXPIRE
OK/ERRMandatory. Indicates whether the event was successful or failed
infoOptional. Information related to the event. A text string consisting of one or more comma-separated fields on a key[=value] format where the value part is optional and may be surrounded by quotation marks, “. Possible key values are: pdu, dlr, orphaned and info.Example:SEND ERR (pdu=1/1,info=”72”):This would indicate a SEND event failed. The pdu sent was one out of one and the protocol specific error code was 72.
optionsOptional. If the event is related to a message, the message MGP options would appear here on a key:value format. 

Sample incoming connector log file

Sep 11 22:34:34.306 (2) CONNECT OK (info="127.0.0.1")
Sep 11 22:34:34.316 (2) LOGIN OK (info="emguser")
Sep 11 22:34:34.433 (2) RECEIVE OK (orphaned) 001:71 034:127.0.0.1 022:stenor 059:mgp 093:1031776474 094:393 008:1234 017:3
Sep 11 22:34:34.468 (2) LOGOUT OK
Sep 11 22:34:34.471 (2) DISCONNECT OK

The log file entry for an incoming MGP connector above shows that an incoming connection from localhost (127.0.0.1) was received, the user “emguser” logged in successfully and one message was received. The message could not be routed and was therefore orphaned. All message options are displayed on a key:value format, for example the recipient MSISDN, 1234, is indicated by MGP option 8 (MGP_OPTION_DESTADDR). Also the message body is not logged, only the message length, three characters, indicated by MGP option 17.

When an operation fails it will be indicate by the text ERR accompanied with a protocol-specific error code within the parenthesis.

Sample outgoing connector log file

Sep 11 22:35:28.664 (4) CONNECT OK
Sep 11 22:35:29.071 (4) LOGIN OK
Sep 11 22:35:30.275 (4) SEND OK (pdu=1/1) 001:71 034:127.0.0.1 022:stenor 059:mgp 093:1031776474 094:393 008:1234 095:1031776530 096:269 017:3
Sep 11 22:35:40.512 (4) LOGOUT OK
Sep 11 22:37:29.007 (4) DISCONNECT OK

The log file entry for an outgoing CIMD2 connector above shows that a connection has been made with a sessionid of 4 and then one message consisting of one PDU has been sent successfully to the end-point. A number of message parameters can also be seen on the format “key:value”.

When an operation fails it will be indicate by the text ERR accompanied with a protocol-specific error code within the parenthesis.

PDU log files

While the connector log files contains message related events encoded as MGP options the PDU log files contains the actual protocol-specific operations being sent and received per connector. The PDU log files will be created either if the connector log level is DEBUG or DEBUG2 or if the connector keyword LOGPDU is present for the connector in question.

The first two fields are always the timestamp and the connector instance name. Established and closed connections are logged, including the SSL version and cipher, if any. For data received or sent, the third column contains “Read” or “Write”, respectively. The rest of the fields very a little depending on the protocol in use, but is typically a list of key-value pairs, or the raw socket data.

Profiling log

In EMG 7.1, a profiling log was added to help finding long running operations. The profiling log is enabled (with threshold 0, log all) when log level DEBUG/DEBUG2 is used. To change the duration threshold, use the keyword PROFILING_THRESHOLD to specify the threshold in seconds. Decimal values are allowed, so 0.1 may be a good place to start.

Not all operations are connected to a connector instance, so instead the thread id is logged between pipe (“|”) characters. The description of the operation itself comes in various formats, and is meant to be self explanatory. The values for “operation” and “incoming” are times spent by EMG, while “roundtrip” are for outgoing requests. You also get values for queue times for each message, the time spent by plugins, and more.

Log file rotation

Log files can be rotated based on time or size using the general keyword ROTATELOGS.

Log file rotation based on time

When log file rotation should be accomplished based on time the log files are rotated with a specified interval. On rotation the current log files are renamed with a timestamp as suffix.

Log file rotation based on size

Log file rotation based on size is accomplished by renaming the log file when it has exceeded a specified size using an index as suffix. The most recently log file rotated out would have “.1” as suffix, the next most recent “.2” and so on up to the specified total number of log files (segments) to save.

Logging to a database

If a database has been prepared for use with EMG it is possible to put the connector log in the database. The connector log files will also be used but it may be convenient to add the information into a database for example for generating statistics in an efficient way.

Message log

The messages are stored in table “routelog”.

Connector log

In order to put the connector log in a database the database must be prepared and a database profile referenced using the general keyword DBPROFILE. Also the general keyword CONNECTORLOGDB needs to be added to the server.cfg file in order to indicate that the log should be put in the database.

The connector log will be stored in the table “connectorlog” which can be found in the schema file included in the EMG distribution.

The event will given using the numeric event values as indicated below:

ValueEvent
ValueEvent
0CONNECT
1DISCONNECT
2LOGIN
3LOGOUT
4SEND
5RECEIVE
7REJECT
9MAXFAIL
10EXPIRE

PDU log

When keyword PDULOGDB is used the pdu log is logged to database (table “pdulog”). Using this feature is not recommended, as the table grows very quickly and therefore needs to be pruned.