This section shows some sample sections of the GWIA log files, and explains how to interpret them. The goal is to help you understand what you see in your own GWIA logs so that you can more effectively administer your system. Log Line FormatEach line in the agent log is divided into four main parts. The first of these is the timestamp, that is, the hour, minute, and second that the event in this log entry occurred. The second part is the process number. This number identifies the server process or thread that performed the operation described in this log entry. If you are trying to follow a thread in the log, you must do so by finding the next occurrence of this number. If process 12 claims to be processing an outbound message, and then process 17 reports an MX lookup error, the error was not with the message in the previous line. Look for the next occurrence of process 12 to see whether the outbound message was processed correctly. Look for the previous occurrence of process 17 to see what it was doing before it got the MX lookup error. The third part, which is not always present, is the process type. This string identifies the service engine that is currently active. When the GWIA is servicing POP3, IMAP4, or LDAP connections, this string will be POP3, IMAP4, or LDAP, respectively. SMTP processing is defined as the DMN process. The fourth part of the log entry is the event description. This might seem a little bit cryptic, but after you have seen a few of them, you will be making sense of them easily. Events you'll see here include error messages, login IDs for POP3 or IMAP users, or descriptions of the conversion and transfer of SMTP/MIME messages. Configuration Information in the GWIA LogHere's the first block of text you will see in the GWIA log, the GWIA configuration: 00:41:58 2BA Starting GWTCP-Dispatcher 00:41:58 2BC Starting GWTCP-Monitor 00:41:58 2BE Starting GWPOP-Listener 00:41:58 2C0 Starting GWIMAP-Listener 00:41:58 28E Begin Configuration Information 00:41:58 28E Platform= NLM 00:41:58 28E Domain and Agent= GWIADOM.GWIA 00:41:58 28E Foreign Name= wwwfs1.worldwidewidgets.com 00:41:58 28E Description= <none specified> 00:41:58 28E Alias Type= <none specified> 00:41:58 28E Root Directory= WWWFS1/SYS:\GWIADOM\WPGATE\GWIA 00:41:58 28E Work Directory= WWWFS1/SYS:\GWIADOM\WPGATE\GWIA\000.prc\gwwork 00:41:58 28E Log File= WWWFS1/SYS:\GWIADOM\WPGATE\GWIA\000.prc\0505gwia.002 00:41:58 28E Directory ID= gwi2c7 These first lines show that at 41 minutes after midnight the GWIA began reading configuration information. These lines correspond to information you might recall entering from the GWIA's Information property page. The GWIA indicates which directory it is working from. The log also includes the name of the current log file, as well as the directory ID of the GWIA. This directory ID is a directory within the DOMAIN\WPGATE\GWIA\WPCSOUT directory that the MTP portion of the GWIA will use to queue messages for the GWIA to send out. The next five lines come from the GWIA's Optional Gateway Settings property page under the GroupWise drop-down tab: 00:41:58 28E Directory Synchronization= NO 00:41:58 28E Directory Exchange= NO 00:41:58 28E Accounting= YES 00:41:58 28E Convert GroupWise Status to Messages= NO 00:41:58 28E Outbound Status Level= UNDELIVERED You can see that accounting has been enabled, and users whose outbound messages cannot be transferred will get an Undeliverable status back. The next lines show the logging level, recovery and retry settings, gateway correlation settings, polling intervals, and time zone information in effect for the GWIA: 00:41:58 28E Log Level= Verbose 00:41:58 28E Log Max Age= 7 days 00:41:58 28E Log Max Space= 34321 kb 00:41:58 28E Enable Recovery= YES 00:41:58 28E Retry Count= 10 00:41:58 28E Retry Interval= 5 seconds 00:41:58 28E Failed Recovery Wait= 3600 seconds 00:41:58 28E Network Reattach Command= <none specified> 00:41:58 28E Correlation DB Enabled= YES 00:41:58 28E Correlation DB Age= 14 days 00:41:58 28E Correlation DB Directory= WWWFS1/SYS:\GWIADOM\WPGATE\GWIA 00:41:58 28E Send/Receive Cycle= 2 minutes 00:41:58 28E Minimum Run= 0 minutes 00:41:58 28E Idle Sleep Duration= 30 seconds 00:41:58 28E Snap Shot Interval= 10 minutes 00:41:58 28E Time Zone= MST 00:41:58 28E GMT Offset= -7 hours, 0 minutes 00:41:58 28E Hemisphere= NORTH 00:41:58 28E Daylight Saving Change= 1 hours, 0 minutes 00:41:58 28E Daylight Saving Begin= 4/3 (month/day) 00:41:58 28E Daylight Saving End= 10/30 (month/day) Some of these settings come from the Optional Gateway Settings property page, some come from the Log Settings property page, and the time zone information is read from the appropriate time zone definition in the domain database. In this last set of configuration entries, the log says that the GWIA will not use a second processor (SMP Off) and that it will publish Simple Network Management Protocol (SNMP) information: 16:12:41 1 SMP Off 16:12:41 1 SNMP On 16:12:41 1 Startup Switches= /Home-\\WWWFS1\MAIL\GWIADOM\WPGATE\GWI 16:12:41 1 A /DHome-\\WWWFS1\MAIL\GWIADOM \WPGATE\GWIA /SMTP /LDAP 16:12:41 1 /MIME /MUDAS=2 /MailView-Internet /SD-16 /RD-8 /P-10 16:12:41 1 /TE-2 /TG-5 /TC-5 /TR-5 /TD-3 /TT-10 /PT-30 /IT-30 / 16:12:41 1 LdapThrd-10 /ST-4 /RT-4 /IRFOUID /SMP /LDAPcntxt=WWWIDGETS 16:12:41 1 S /POP3 /IMAP4 16:12:41 1 End Configuration Information 16:12:41 1 MTP: Message Transfer Protocol initialization... 16:12:41 1 MTP: Queue initialization... 16:12:41 1 MTP: Queue initialization... 16:12:41 1 Starting GWPOP-Handler_1 16:12:41 1 Starting GWIMAP-Handler_1 16:12:41 1 End Configuration Information The log also shows all the startup switches that have been written to the GWIA.CFG file. These switches govern the number of threads for the various services, among other things. Finally the log shows that the MTP, POP, and IMAP threads of the GWIA are initialized. Message Processing Log EntriesWhen the GWIA processes a message that was sent from a GroupWise user to a recipient on the Internet, the log entries look a lot like this: 1. 08:01:30 7 MSG 6 Processing outbound message... 2. 08:01:30 7 MSG 6 File: ERAFF1/MAIL:\GW6\DO1\WPGATE\GWIA\wpcsout\gwif 94a\4\4EF956D2.M80 Message Id: (3EF9AB2B.B51:8:40818) Size: 455 3. 08:01:30 7 MSG 6 Sender: ecornish@wwwidgets.com 4. 08:01:30 7 MSG 6 Converting message to MIME: ERAFF1/MAIL:\GW6\DO1\WP GATE\GWIA\send\xef956d8.001 5. 08:01:30 7 MSG 6 Recipient: glenn@brown.com 6. 08:01:30 7 Switching link state to SENDING_ALLOWED. 7. 08:01:30 7 MSG 6 Queuing message to daemon: ERAFF1/MAIL:\GW6\DO1\WPG i. ATE\GWIA\send\sef956d8.001 8. 08:01:30 7 DMN: MSG 7 Sending file: ERAFF1/MAIL:\GW6\DO1\WPGATE\GWIA i. \send\pef956d8.001 9. 08:01:30 7 DMN: MSG 7 Connected to mail-mx.brown.com 10. 08:01:30 7 DMN: MSG 7 Transferred Let's break down the 10 log lines from one piece of mail being sent from ecornish@wwwidgets.com to glenn@brown.com.
The logging of the GroupWise 7 GWIA is much improved, and this is easily double the amount of logging about a sent message that the GroupWise 6 GWIA reported. You can much more easily identify that this message was successfully transferred to the destination SMTP gateway. As you can see, from the GWIA log you can see exactly which users on your system are sending mail to Internet users, and you can capture every address. You can also see which Internet users are sending email to which users on your system. We know of at least one case in which information from a GWIA log has been used to expose users who were selling company secrets to the competition. Your users might consider this to be an infringement on their privacy, so you should be sure to word your organization's email policy in such a way as to allow you to scan GWIA logs freely. Here's a look at what happens with an SMTP error: 13:54:13 0 Analyzing result file: r83a9c7e.084 13:54:41 0 Analyzing result file: r83a9c5d.083 13:54:41 0 Command: stribling.com 13:54:41 0 Response: 250 ok 13:54:41 0 Command: HELO mail.wwwidgets.com 13:54:41 0 Response: 250 Hello mail.wwwidgets.com [137.65.55.211], pleased to meet you 13:54:41 0 Command: MAIL FROM:<edekorte@wwwidgets.com> 13:54:41 0 Response: 250 <edekorte@wwwidgets.com>.. Sender ok 13:54:41 0 Detected error on SMTP command 13:54:41 0 Command: RCPT TO:<darren@stribling.com> 13:54:41 0 Response: 420 TCP read error This file shows that process 0 analyzed a result file named r83a9c7e.084. This result file corresponds to an SMTP communication. Because there's no more information about this result file, you know that the communication was error free. In the second line, process 0 picks up another result file to analyze, and this one has an error in it. Scanning through the available information, you can see that user edekorte@wwwidgets.com sent a message to darren@stribling.com. The GWIA looked up and then opened a connection with the stribling.com mail host. You can see this from the successful HELO commands and the success of the first MAIL command. Unfortunately, the GWIA got a TCP read error trying to transmit the recipient address. This indicates that the connection between wwwidgets.com and stribling.com is too noisy, was dropped, or timed out. Unfortunately, the result file does not indicate what time these events occurred. What is visible is the GWIA's analysis of the SMTP daemons actions after the fact. POP3 Connection Log EntriesEach time a user initiates a POP3 connection with the GWIA, that action is logged. Here is a sample of such a connection: 13:53:59 8 Accepted POP3 connection with: 10.10.40.232 13:53:59 8 POP3 Command: USER ksorensen 13:53:59 8 Successful login with client/server access: wwwfs1.wwwidgets.com:1677 13:53:59 8 POP3 Command: PASS 13:53:59 8 POP3 Command: STAT 13:53:59 8 POP3 Command: QUIT 13:53:59 8 POP3 Session ended: 10.10.40.232 Process 8 handled the entire connection, as to be expected, because the GWIA can have only as many simultaneous POP3 sessions as it has POP3 threads. The log shows the IP address of the user workstation that is running the POP3 mailer, and then the log indicates which POP3 commands were issued. The entire POP3 connection lasted only a second, and then process 8 was free to service another connection or return to the pool of idle threads. |