Recipe8.23.Using Protocol Logging


Recipe 8.23. Using Protocol Logging

Problem

You need to log the specific protocol transactions of HTTP, NNTP, or SMTP sessions.

Solution

Using a graphical user interface

  1. Open the property sheet of the desired virtual server:

    • If you need to enable logging on an HTTP virtual server, launch the IIS management snap-in and open the property sheet of the Default Web Site to the General tab.

    • If you need to enable logging on an NNTP virtual server, launch Exchange System Manager, navigate to the desired server object, expand Protocols, expand NNTP, and open the property sheet of the desired virtual server to the General tab.

    • If you need to enable logging on an SMTP virtual server, launch Exchange System Manager, navigate to the desired server object, expand Protocols, expand SMTP, and open the property sheet of the desired virtual server to the General tab.

  2. Select Enable Logging and select W3C Extended Log File Format.

  3. Click Properties and select the General tab.

  4. Select your desired log schedule: hourly, daily, weekly, monthly, unlimited file size, or specified file size.

  5. If you will be comparing entries in this log with logs from other systems such as Unix servers or servers in other time zones, clear the Use local time for file naming and rollover checkbox to instruct Exchange to use UTC timing.

  6. Ensure that the log file path shown in the Log file directory field is satisfactory.

  7. Click the Advanced tab, select the specific fields to be logged, and then click OK twice to close the virtual server property sheet.

Discussion

Although most Exchange deployments use some version of Outlook (and thus the MAPI protocol) for the majority of their clients, the ability to access Exchange resources via Internet standard protocols such as HTTP, NNTP, and SMTP allows many users to make use of a wide variety of other messaging software. It is much easier to troubleshoot difficulties with these clients and services with a detailed log of the protocol transaction; as an example, comparing logs of an SMTP conversation from an Exchange server and from the remote SMTP sender will provide an immediate pointer toward the trouble caused by a Cisco PIX firewall with the SMTP fixup feature enabled (see Recipe 8.24).

One method to spot these kinds of problems is to use a network packet sniffer, but this approach has many drawbacks, not the least of which is the necessity to manually decode the relevant information from the raw packet capture. On the other hand, most packet sniffers allow you to specify filters and reduce the fire hose of information down to a stream you can drink from without drowning, but you still may have to parse the resulting information by hand, although some packet sniffers do packet/session reconstruction for you.

Since Exchange wraps and extends the HTTP, NNTP, and SMTP components of IIS, there is another alternative: using the built-in logging capabilities of the appropriate virtual server. While you might not want to enable protocol logging for normal operation, as it can use disk and CPU resources and may slow down a busy virtual server, it is a valuable troubleshooting tool that can be easily enabled from within Exchange System Manager (or the Internet Services Manager for an HTTP virtual server).

Since protocol logging is enabled and disabled per virtual server, the performance hit can cause problems on a high-traffic server that only has the default virtual servers configured. One way to avoid this problem is to put some thought into configuring multiple virtual servers, as appropriate, to segment your traffic. For example, a bridgehead server for the external SMTP connector could probably benefit from a separate SMTP virtual server specifically for external traffic; whenever protocol logging is turned on to troubleshoot problems with external systems, none of the communications with the other Exchange servers in the organization will be logged. This needs to be balanced against the need to simplify the configuration as much as possible.

Protocol logs can be created in four formats: W3C Extended format, Microsoft IIS format, NCSA Common format, and ODBC. Oddly enough, the preferred format (and default) is the W3C Extended format. This format gives a rich set of properties across multiple protocols; while not every property is supported by every protocol, each property is used in the same way for each protocol that supports that property, allowing your administrators to use their familiarity with one protocol to read logs from another.

The first three formats are ASCII text files; the ODBC format writes each entry as a separate record to a preconfigured data source, allowing easy integration of logs from multiple sources into one central database, which can then be searched and filtered using standard database queries. Table 8-6 describes all the possible fields of the W3C Extended format.

Table 8-6. W3C Extended log file format

Field

Data

date

Date.

time

Time.

c-ip

Client IP address.

cs-username

Authenticated user name. An unauthenticated or anonymous user will display hyphen for HTTP, <user> for NNTP, and the client FQDN for SMTP.

s-sitename

The Internet service name and instance number.

s-computername

Server name; the name of the server on which the log entry was generated.

s-ip

Server IP address.

s-port

Server IP port.

cs-method

HTTP method or SMTP/NNTP verb requested by the client.

cs-uri-stem

URI stem. For HTTP, the file requested; for NNTP, the applicable group or article. Not used for SMTP.

cs-uri-query

URI query. For HTTP, the parameters passed; for SMTP, the parameters for the verb. Not used for NNTP.

sc-status

Numeric protocol status code.

sc-substatus

Numeric substatus code. Only available for HTTP virtual servers.

sc-win32-status

Numeric Win32 status code.

sc-bytes

Number of bytes sent from the server to the client.

cs-bytes

Number of bytes received by the server from the client.

time-taken

Number of milliseconds used to process this portion of the transaction.

cs-version

Protocol and version used by the client; will be either HTTP/1.0, HTTP/1.1, NNTP, or SMTP.

cs-host Host

The requested host header; used only for HTTP/1.1.

cs(User-Agent)

The browser identification string supplied by the client. Not used for NNTP or SMTP.

cs(Cookie)

The content, if any, of any cookie sent or received. Not used for NNTP or SMTP.

cs(Referrer)

The referring site previously visited by the user. Not used for NNTP or SMTP.


The following sample HTTP log sample shows the beginning of an OWA login:

 1  #Software: Microsoft Internet Information Services 6.0 2  #Version: 1.0 3  #Date: 2004-10-29 02:11:58 4  #Fields: date time s-sitename s-computername s-ip cs-method cs-uri-stem     cs-uri-query s-port cs-username c-ip cs-version cs(User-Agent) cs(Cookie)     cs(Referer) cs-host sc-status sc-substatus sc-win32-status sc-bytes     cs-bytes time-taken  5  2004-10-29 02:11:58 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/     - 80 - 10.0.0.10 HTTP/1.1 Mozilla/4.0+(compatible;+MSIE+6.0;+Windows+    NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+CLR+1.1.4322) - - EXCH01 401 2     2148074254 337 402 30 6  2004-10-29 02:11:59 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/     - 80 THECABAL\devin 10.0.0.10 HTTP/1.1 Mozilla/4.0+(compatible;+MSIE+    6.0;+Windows+NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+CLR+1.1.4322) - -     EXCH01 200 0 0 1694 2121 420 7  2004-10-29 02:11:59 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/    devin/ Cmd=navbar 80 - 10.0.0.10 HTTP/1.1 Mozilla/4.0+(compatible;+MSIE+    6.0;+Windows+NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+CLR+1.1.4322) sessionid=    664eb14a-bc2b-4239-a688-d0197f094aff:0x409 http://exch01.thecabal.org/    exchange/ EXCH01 401 2 2148074254 337 515 50 8  2004-10-29 02:11:59 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/    devin/Inbox/ Cmd=contents 80 - 10.0.0.10 HTTP/1.1 Mozilla/4.0+(compatible;    +MSIE+6.0;+Windows+NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+CLR+1.1.4322)     sessionid=664eb14a-bc2b-4239-a688-d0197f094aff:0x409 http://exch01.thecabal.    org/exchange/ EXCH01 401 2 2148074254 337 523 100 9  2004-10-29 02:11:59 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/    devin/ Cmd=navbar 80 THECABAL\devin 10.0.0.10 HTTP/1.1 Mozilla/4.0+    (compatible;+MSIE+6.0;+Windows+NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+CLR+    1.1.4322) sessionid=664eb14a-bc2b-4239-a688-d0197f094aff:0x409 http://    exch01.thecabal.org/exchange/ EXCH01 200 0 0 17646 2234 420 10 2004-10-29 02:11:59 W3SVC1 exch01.thecabal.org 10.0.0.20 GET /exchange/    devin/Inbox/ Cmd=contents 80 THECABAL\devin 10.0.0.10 HTTP/1.1 Mozilla/    4.0+(compatible;+MSIE+6.0;+Windows+NT+5.1;+SV1;+.NET+CLR+1.0.3705;+.NET+    CLR+1.1.4322) sessionid=664eb14a-bc2b-4239-a688-d0197f094aff:0x409 http://    exch01.thecabal.org/exchange/ EXCH01 200 0 0 19616 2242 390

Lines 5 through 10 of the HTTP log sample show the initial requests; the browser is a member of the domain and the OWA server is not using form authentication, so the request is authenticated using NTLM credentials on the second successive request. Lines 7 through 10, in particular, show how the various requests are broken over the cs-method, cs-uri-stem, and cs-uri-query fields.

The following sample NNTP log shows a short NNTP session:

 1  #Software: Microsoft Internet Information Services 6.0 2  #Version: 1.0 3  #Date: 2004-10-29 02:14:55 4  #Fields: date time c-ip cs-username s-sitename s-computername s-ip s-port cs-method     cs-uri-stem cs-uri-query sc-status sc-win32-status sc-bytes cs-bytes time-taken cs-    version cs-host cs(User-Agent) cs(Cookie) cs(Referer)  5  2004-10-29 02:14:55 10.0.0.10 <user> NNTPSVC1 EXCH01 10.0.0.20 119 - - - 0 0 0 0     21642 NNTP - - - - 6  2004-10-29 02:16:45 10.0.0.10 thecabal\devin NNTPSVC1 EXCH01 10.0.0.20 119 post     thecabal.test - 240 600 70 6 108522 NNTP - - - - 7  2004-10-29 02:16:56 10.0.0.10 thecabal\devin NNTPSVC1 EXCH01 10.0.0.20 119 article     1+<2X9ZW1VvEHA.2288@EXCH01.thecabal.org> 1 220 0 669 11 119689 NNTP - - - - 8  2004-10-29 02:17:11 10.0.0.10 thecabal\devin NNTPSVC1 EXCH01 10.0.0.20 119 quit - -     205 0 35 6 134621 NNTP - - - - 9  2004-10-29 02:17:11 10.0.0.10 thecabal\devin NNTPSVC1 EXCH01 10.0.0.20 119 - - - 0 0     0 0 134621 NNTP - - - -

Line 5 of the NNTP log shows the initial nonauthenticated connection from the client. In line 6, the user creates a new post to the thecabal.test newsgroup. In line 7, this article is retrieved and read. Lines 8 and 9 show the disconnection from the server.

The following sample SMTP log shows an incoming message:

 1  #Software: Microsoft Internet Information Services 6.0 2  #Version: 1.0 3  #Date: 2004-10-29 02:12:25 4  #Fields: date time c-ip cs-username s-sitename s-computername s-ip s-port cs-method     cs-uri-stem cs-uri-query sc-status sc-win32-status sc-bytes cs-bytes time-taken     cs-version cs-host cs(User-Agent) cs(Cookie) cs(Referer)  5  2004-10-29 02:12:25 10.0.0.30 cli01.thecabal.org SMTPSVC1 EXCH01 10.0.0.20 0 EHLO -     +cli01.thecabal.org 250 0 317 22 431 SMTP - - - - 6  2004-10-29 02:12:46 10.0.0.30 cli01.thecabal.org SMTPSVC1 EXCH01 10.0.0.20 0 MAIL -     +from:<devin@thecabal.org> 250 0 43 30 381 SMTP - - - - 7  2004-10-29 02:12:56 10.0.0.30 cli01.thecabal.org SMTPSVC1 EXCH01 10.0.0.20 0 RCPT -     +to:<devin@thecabal.org> 250 0 36 33 0 SMTP - - - - 8  2004-10-29 02:13:34 10.0.0.30 cli01.thecabal.org SMTPSVC1 EXCH01 10.0.0.20 0 DATA -     <EXCH01iFkYzLiNOyl7u00000001@EXCH01.thecabal.org> 250 0 137 179 34910      SMTP - - - - 9  2004-10-29 02:13:36 10.0.0.30 cli01.thecabal.org SMTPSVC1 EXCH01 10.0.0.20 0 QUIT -     cli01.thecabal.org 240 75399 73 4 0 SMTP - - - -

Line 5 of the SMTP log shows the initial connection, which uses the EHLO Extended SMTP greeting. Because the cs-username field shows the FQDN of the SMTP client, this connection is not using SMTP authentication.

Lines 6 through 8 show the submission of the message: MAIL FROM and RCPT TO to provide the envelope information and DATA to submit the message itself. At each step, the incoming message passed the various connection, sender, and recipient checks, as shown by the sc-status codes of 250 (OK). Line 9 shows the disconnection.

When trying to write scripts to control protocol logging, you will find a distinct lack of information on how this can be done. In theory, it's a simple matter of selecting the desired physical server, protocol, and virtual server, then adjusting a few properties in the IIS metabase to control the particular parameters; in reality, there are undocumented interactions with the Exchange extensions to the IIS protocol components. Protocol logging is disabled by default and should be enabled only during troubleshooting and on only the specific virtual servers involved because it has the potential to impact production performance severely. Therefore, we have only included information on enabling protocol logging through the GUI.

See Also

Recipe 7.26 for testing the SMTP server through a manual telnet session, MS KB 257265 (General troubleshooting for Exchange 2000 transport issues), MS KB 821910 (How to troubleshoot for Exchange Server 2003 transport issues), and:

http://www.microsoft.com/resources/documentation/WindowsServ/2003/standard/proddocs/en-us/ref_we_logging.asp

for a reference on the properties in the various logging formats



Exchange Server Cookbook
Exchange Server Cookbook: For Exchange Server 2003 and Exchange 2000 Server
ISBN: 0596007175
EAN: 2147483647
Year: 2006
Pages: 235

flylib.com © 2008-2017.
If you may any questions please contact us: flylib@qtcs.net