12 Logging Events, Diagnostics, and Access Information

This chapter explains how to use OracleAS Web Cache event and access logs.

This chapter contains these topics:

Evaluating Event Logs
Displaying Diagnostic and Event Log Information in the HTML Body or Server-Response Header Field
Evaluating Access Logs

12.1 Evaluating Event Logs

OracleAS Web Cache events and errors are stored in an event log. The event log can help you determine which documents or objects have been inserted into the cache. It can also identify listening port conflicts or startup and shutdown issues. By default, the event log has a file name of event_log and is stored in $ORACLE_HOME/webcache/logs on UNIX and ORACLE_HOME\webcache\logs on Windows.

This section contains the following topics:

Format of the Event Log File
Configuring Event Logs
Event Log Examples

See Also:
Chapter 16 for descriptions of the event log messages

12.1.1 Format of the Event Log File

Event messages are written using either of the following formats:

The default format displays a typical log message for each instance of an event. It displays the request ID and sequence number of the Oracle-ECID request header so that you can easily find the matching request detail line.
```
[Timestamp][severity message_id][ecid: request_id, serial_number] Event_Log_Message
```
The request detail format is displayed when you enable Include Request Details. The field [detail] indicates that the event is for a request. This format is logged the first time an event is logged for a request. In addition to the IP address, site name, and URL of the request, the ID and sequence number of the Oracle-ECID request header is logged. The Oracle-ECID request header is used to track requests.
```
[Timestamp][module_name][detail][ecid: request_id, hop_number] [client: IP_address] [host: site] [url: URL]
```

Table 12-1 describes the fields for the default event log format.

Table 12-1 Event Log Format

Fields	Description
[`Timestamp`]	Date when the event occurred. Time is displayed in either local or Greenwich Mean Time.
[`severity` `message_id`]	Severity level and message ID of event log message. Severity level can be one of the following: `internal error`: An event that occurs due to a bug `alert`: An event that affects the entire OracleAS Web Cache instance and causes a lack of service in subsequent request/response transaction `error`: An event that causes a lack of service only within the request/response transaction `warning`: An event which is abnormal or potentially a sign of some problem `notification`: An event that provides current status `trace`: An event that indicates a trace activity `debug`: An event that is a trace activity intended for Oracle Support Services and development
`[ecid:` `request_id``,` `serial_number``]`	Request ID and hop-sequence number from the `Oracle-ECID` request header
`Event_Log_Message`	Event message

Table 12-2 describes the fields for the request detail format.

Table 12-2 Event Log Format for Request Details

Fields	Description
`[Timestamp]`	Date when the event occurred. Time is either displayed in local or Greenwich Mean Time.
`[detail]`	Request detail event
`[ecid:` `request_id``,` `serial_number``]`	Request ID and sequence number from the `Oracle-ECID` request header
`[client:` `IP_address``]`	IP address of the browser that made the request
`[host:` `site``]`	Site name of the request
`[url:` `URL``]`	URL of the request

See Also:

"Oracle-ECID Request-Header Field" for a more detailed description of the Oracle-ECID request header
"Configuring Event Logs" for further information about enabling the Include Request Details feature

12.1.2 Configuring Event Logs

To configure the event log settings:

Start OracleAS Web Cache Manager.

See Also:
"Starting OracleAS Web Cache Manager"
In the navigator frame, select Logging and Diagnostics > Event Logs.

The Event Logs page appears.

Specify cache-specific event log settings:

From the Cache-Specific Event Log Configuration table, select a cache, and then click Edit Selected.

The Edit Cache-Specific Event Log Configuration dialog box appears.
In the Directory field, enter the directory in which to write event logs.

The default is $ORACLE_HOME/webcache/logs on UNIX and ORACLE_HOME\webcache\logs on Windows.
In the Buffering field, select Enabled to enable buffered logging or Disabled to disable buffered logging.

With buffered logging, OracleAS Web Cache writes to the event log after the buffer is full. The buffer size is set 2048 bytes. When the limit is reached, OracleAS Web Cache writes buffered events to the event log file.

Oracle Corporation recommends disabling buffering when you need to see the event log results immediately, such as when you are debugging OracleAS Web Cache.
If buffering is enabled, set the frequency at which buffered events are written to the event log file in the Flush Interval field.

The default is 10 seconds. When the interval is reached, OracleAS Web Cache writes buffered events to the event log file. Even if the buffer is not full, the event log is updated at least every 10 seconds. Oracle Corporation recommends not changing the default unless you need to lower the interval to see results more frequently.

From the Verbosity list, select the needed level of detail for the event log. The levels are described in Table 12-3.

Table 12-3 Verbosity Levels

Level	Description
WARNING	Provides abnormal-operation events.
NOTIFICATION	Provides normal-operation events, such as startup and shutdown. This is the default.
TRACE	Provides events for debugging caching rules.
DEBUG	Provides detailed events for troubleshooting. This level is intended for Oracle Support Services.

Click Submit.

Set the global event log settings:

From the Global Event Log Configuration table, click Edit.

The Edit Global Event Log Configuration dialog box appears.
In the File Name field, enter a name for the event log file.

The default file name is event_log.

From the Time Style list, select either LOCAL or GMT to modify the time stamp style associated with entries in the event log file.

Note:

Oracle Corporation recommends using GMT whenever possible. Local can be CPU-intensive, because of the conversion process from GMT to Local time. This conversion process is supplied by the operation system. As such, OracleAS Web Cache has no mechanism to improve the performance of the conversion process.

In Include Request Details, select Yes to enable the logging of request details or No to disable logging of requests.

Oracle Corporation recommends selecting No if either of the following conditions apply:

You are concerned about the performance impact of event log entries for request details

You are running OracleAS Web Cache in a standalone environment without Oracle HTTP Server

See Also:

"Format of the Event Log File" for further information about how request details are logged
Appendix C for information about running OracleAS Web Cache in a standalone environment

In the Rollover Policy section, select Weekly, Daily, Hourly, or Never to specify how often you want OracleAS Web Cache to save current log information to event_log_file.yyyymmdd and write new log information to the current event log file.

Table 12-4 describes additional configuration instructions for Weekly, Daily, and Hourly.

Table 12-4 Configuring Weekly, Daily and Hourly Rollover Policies

Policy	To configure:
Weekly	Select a day of the week. Use the Time fields to enter the hour and minutes. From the Time Style list, select either Local or GMT.
Daily	From the Rollover times - each day list, select a time. If the time you require does not exist, use the Time fields to enter the hour and minutes. From the Time Style list, select either Local or GMT.
Hourly	From the Rollover times - minutes past the hour list, select a time. If the time you require does not exist, use the Minutes past the hour field to enter the number of minutes, and then click Add. From the Time Style list, select either Local or GMT.

If you have a high-volume site, create a daily or hourly policy.

See Also:

"Rolling Over Event and Access Logs " for instructions on immediately rolling over log files

Click Submit.

Apply changes and restart OracleAS Web Cache:
1. In the OracleAS Web Cache Manager main window, choose Apply Changes.
2. In the Cache Operations page, choose Restart to restart OracleAS Web Cache.

12.1.3 Event Log Examples

This section contains the following event log examples:

Example: Event Log with Startup Entries
Example: Event Log with Unsuccessful Startup Entries
Example: Event Log with Shutdown Entries
Example: Event Log with Cache Miss and Cache Hit Entries
Example: Event Log with an Invalidation Entry
Example: Event Log with Invalidation Request Errors
Example: Event Log with ESI Parsing Errors
Example: Event Log with ESI Processing Errors

Example: Event Log with Startup Entries

The following shows an event log excerpt with successful startup entries:

[25/Jun/2003:19:08:52 +0000] [notification 9612] [ecid: -]  OracleAS Web Cache version number: 9.0.4
[25/Jun/2003:19:08:52 +0000] [notification 9403] [ecid: -] Maximum number of file/socket descriptors set to 950.
[25/Jun/2003:19:08:52 +0000] [notification 13002] [ecid: -] Maximum allowed incoming connections are 700
[25/Jun/2003:20:44:37 +0000] [notification 12209] [ecid: -] A 1 node cluster successfully initialized
[25/Jun/2003:19:08:52 +0000] [notification 9608] [ecid: -]  The cache server process started successfully.

Example: Event Log with Unsuccessful Startup Entries

The following shows an event log excerpt with unsuccessful startup events. OracleAS Web Cache is unable to listen on port 7777, because it is already in use. This can occur if OracleAS Web Cache is already running and listening on that port or another application is using that port.

[25/Jun/2003:19:12:40 +0000] [notification 9612] [ecid: -]  OracleAS Web Cache version number: 9.0.4
[25/Jun/2003:19:12:40 +0000] [notification 9403] [ecid: -] Maximum number of file/socket descriptors set to 950.
[25/Jun/2003:19:12:40 +0000] [notification 13002] [ecid: -] Maximum allowed incoming connections are 700
[25/Jun/2003:19:12:40 +0000] [alert 13305] [ecid: -] failed to assign port 7777, bind() error = Address already in use
[25/Jun/2003:19:12:40 +0000] [alert 9707] [ecid: -]  Failed to start the server.
[25/Jun/2003:19:12:40 +0000] [alert 9609] [ecid: -] The server process could not initialize.
[25/Jun/2003:19:12:40 +0000] [notification 9610] [ecid: -]  The server is exiting.

Example: Event Log with Shutdown Entries

The following shows an event log excerpt with typical shutdown entries:

[25/Jun/2003:19:09:49 +0000] [notification 9703] [ecid: -] Stop Issued. The program will shut down after all accepted requests are served, or a timeout occurs. 
[25/Jun/2003:19:09:49 +0000] [notification 9610] [ecid: -]  The server is exiting.

Example: Event Log with Cache Miss and Cache Hit Entries

The following shows an event log excerpt containing events for a cache-miss request:

[25/Jun/2003:19:46:26 +0000] [detail] [ecid: 20910180667,0] [client: 130.35.44.78] [host: www.company.com:80] [url: /index.html] 
[25/Jun/2003:19:46:26 +0000] [trace 11331] [ecid: 20910180667,0] The host request header matches configured site www.company.com:80.
[25/Jun/2003:19:46:26 +0000] [trace 11351] [ecid: 20910180667,0] The complete site name is: www.company.com:80
[25/Jun/2003:19:46:26 +0000] [trace 11414] [ecid: 20910180667,0] The initial cache key is composed: /www.company.com:80/index.html .
[25/Jun/2003:19:46:26 +0000] [trace 11304] [ecid: 20910180667,0] Cache miss request.
[25/Jun/2003:19:46:26 +0000] [trace 11224] [ecid: 20910180667,0] Site www.company.com:80 matches site-to-server mapping www.company.com:80.
[25/Jun/2003:19:46:26 +0000] [trace 11227] [ecid: 20910180667,0] Request is routed to origin server hhayashi-sun:7778 (id=0) using load balancing for site www.company.com:80.
[25/Jun/2003:19:46:27 +0000] [trace 11403] [ecid: 20910180667,0] begin cacheability decision for following URL www.company.com:80/index.html
[25/Jun/2003:19:46:27 +0000] [trace 11407] [ecid: 20910180667,0] URL matches caching rule \.html?$.
[25/Jun/2003:19:46:27 +0000] [trace 11446] [ecid: 20910180667,0] URL which will be cached is: www.company.com:80/index.html
[25/Jun/2003:19:46:27 +0000] [trace 11415] [ecid: 20910180667,0] Final cache key is composed: /www.company.com:80/index.html .
[25/Jun/2003:19:46:27 +0000] [trace 11088] [ecid: 20910180667,0] The following URL is now in the cache: www.company.com:80/index.html

The following shows an event log excerpt containing events for a subsequent cache-hit request:

[25/Jun/2003:19:46:58 +0000] [detail] [ecid: 20910213770,0] [client: 130.35.44.78] [host: www.company.com:80] [url: /index.html] 
[25/Jun/2003:19:46:58 +0000] [trace 11331] [ecid: 20910213770,0] Host request header matches configured site www.company.com:80.
[25/Jun/2003:19:46:58 +0000] [trace 11351] [ecid: 20910213770,0] The completed site name is: www.company.com:80
[25/Jun/2003:19:46:58 +0000] [trace 11414] [ecid: 20910213770,0] Initial cache key is composed: /www.company.com:80/index.html .
[25/Jun/2003:19:46:58 +0000] [trace 11415] [ecid: 20910213770,0] Final cache key is composed: /www.company.com:80/index.html .
[25/Jun/2003:19:46:58 +0000] [trace 11338] [ecid: 20910213770,0] URL is in the cache.
[25/Jun/2003:19:46:58 +0000] [trace 11344] [ecid: 20910213770,0] Returning a freshly cached document.

Example: Event Log with an Invalidation Entry

The following shows an event log excerpt with an event associated with an invalidation request for the removal of document cache.htm.

[13/Dec/2002:19:26:46 +0000] [notification 11706][ecid: 21085932167,0] 10 objects (s) matching prefix '/cache/' are invalidated.
[13/Dec/2002:19:26:46 +0000] [notification 11748] [ecid: 21085932167,0] Invalidation with INFO 'removing 15k document' has returned with status ' SUCCESS'; number of documents invalidated: '10'.

Example: Event Log with Invalidation Request Errors

The following shows an event log excerpt with an XML invalidation request error. In this example, OracleAS Web Cache is unable to parse the request.

[13/Dec/2002:19:37:36 +0000] [alert 13109] [ecid: 21086599201,0] XML parsing error in N/A. Error code 210: LPX-00210: expected '=' instead of 'H'
[13/Dec/2002:19:37:36 +0000] [error 13112] [ecid: 21086599201,0] XML parsing failed. Error Code: 210
[13/Dec/2002:19:37:36 +0000] [error 11716] [ecid: 21086599201,0]
Invalidation XML message cannot be parsed.

Example: Event Log with ESI Parsing Errors

The following shows an event log excerpt with ESI parsing errors that indicate a problem with the src attribute and variable syntax:

[16/Jan/2003:01:59:48 +0000] [detail] [ecid: 19734744942,0] [client: 127.0.0.1] [host: www.company.com:80] [url: /cgi-bin/esi-headers.sh?err1.htm] 
[16/Jan/2003:01:59:48 +0000] [error 12086] [ecid: 19734744942,0] ESI syntax error. Unrecognized keyword src is at line 3.
[16/Jan/2003:01:59:48 +0000] [warning 11064] [ecid: 19734744942,0] ESI document www.company.com:80/cgi-bin/esi-headers.sh?err1.htm parsing error
...
[16/Jan/2003:02:11:57 +0000] [detail] [ecid: 19735486051,0] [client: 127.0.0.1] [host: www.company.com] [url: /cgi-bin/esi-headers.sh?err1.htm] 
[16/Jan/2003:02:11:57 +0000] [error 12095] [ecid: 19735486051,0]  ESI syntax error. A variable requires a key at line 3.
[16/Jan/2003:02:11:57 +0000] [warning 11064] [ecid: 19735486051,0] ESI document www.company.com:80/cgi-bin/esi-headers.sh?err1.htm parsing error

Example: Event Log with ESI Processing Errors

The following shows an event log excerpt with ESI processing errors that indicate an error fetching an ESI fragment named a.html and an unknown fragment for an undefined site:

[16/Jan/2003:02:02:37 +0000] [detail] [ecid: 19734914560,0] [client: 127.0.0.1] [host: www.company.com:80] [url: /cgi-bin/esi-headers.sh?err1.htm] 
[16/Jan/2003:02:02:37 +0000] [warning 12005] [ecid: 19734914560,0] HTTP Client Error 4xx exception in ESI template www.company.com:80/cgi-bin/esi-headers.sh?err1.htm, 
fragment www.company.com:80/cgi-bin/a.html
....
[16/Jan/2003:02:03:38 +0000] [detail] [ecid: 19734980113,0] [client: 127.0.0.1] [host: -] [url: /cgi-bin/esi-headers.sh?err1.htm] 
[16/Jan/2003:02:03:38 +0000] [warning 11295] [ecid: 19734980113,0] OracleAS Web Cache failed in DNS lookup for host www.company2.com:80. 
[16/Jan/2003:02:03:38 +0000] [warning 12003] [ecid: 19734980113,0] No connection exception in ESI template www.company.com:80/cgi-bin/esi-headers.sh?err1.htm, fragment www.company2.com:80/a.html

12.2 Displaying Diagnostic and Event Log Information in the HTML Body or Server-Response Header Field

By default, OracleAS Web Cache adds diagnostics information to the Server-response header field:

Server: OracleAS/version Server_header_from_origin_server OracleAS-Web-Cache/version (diagnostic_information)

For diagnostics purposes, it can be useful to also display this information in the HTML response body of a document. Once enabled, you simply append a string to the URL of the document into the browser to see the diagnostic information string embedded in the response body. In addition to diagnostics information, you can optionally display event log information, with a verbosity level of TRACE, in the HTML response.

See Also:

Table 2-4 for a detailed description of the diagnostic information displayed

To configure where to display diagnostic information:

In the navigator frame, select Logging and Diagnostics > Diagnostics.

The Diagnostics page appears.
From the Cache-Specific Page Body Diagnostics table, select a cache, and then click Enable to display diagnostic information in the HTML response body or Disable to disable the display of diagnostic information in the HTML response body.
To set diagnostic settings for the HTML response body:
1. Click Edit.
  
  The Edit Global Page Body Diagnostics Configuration dialog box displays.
2. In the URL Flag field, enter the string to append to the URL of the document.
  
  By default, the string is set to +wcdebug.
3. In the Display Event Log Entries for Request field, select Yes to display diagnostic information and TRACE event log entries in the HTML response body, or select No to only display diagnostic information.
4. Click Submit.
To enable or disable diagnostic settings in the Server response header, from the Global Server Header Diagnostics table, click Enable or Disable.

Note:

When a page is compressed, OracleAS Web Cache does not add debug information.

12.3 Evaluating Access Logs

OracleAS Web Cache generates an access log that contains information about the HTTP requests sent to OracleAS Web Cache. By default, the access log has a file name of access_log and is stored in $ORACLE_HOME/webcache/logs on UNIX and ORACLE_HOME\webcache\logs on Windows.

This section contains the following topics:

Format of the Access Log Files
Configuring Access Logs
Analyzing an Access Log File
Access Log Examples

See Also:
Oracle Application Server 10g Administrator's Guide for further information about managing log files with Oracle Enterprise Manager

12.3.1 Format of the Access Log File s

You can configure the content of the access log files by defining the fields to appear for each HTTP request event. These fields are based on the Extended LogFile Format (XLF). By default, OracleAS Web Cache provides support the following log formats:

Common LogFile Format (CLF)

This format is the default format applied to access logs. This format is appropriate for most configurations.

The CLF format provides support for the following fields:
- c-ip
- x-log-id
- x-auth-id
- x-clf-date
- x-req-line
- sc-status
- bytes
Combined Format

The combined format provides support for the CLF fields and the following additional fields:
- cs(Referer)
- cs(User-Agent)
Select this format when you need to determine what kind of browser is sending the request, and where the browser was visiting before the request was forwarded to OracleAS Web Cache.
Web Cache Log Format (WCLF)

This format provides support for the following fields intended for end-user performance monitoring features:
- x-req-type
- x-date-start
- x-time-start
- c-ip
- s-ip
- x-auth-id
- cs(Host)
- cs-method
- cs-uri
- x-protocol
- sc-status
- bytes
- cs-bytes
- x-cache
- time-taken
- r-time-taken
- x-time-delay
- x-os-timeout
- x-ecid
- x-cookie(ORACLE_SMP_CHRONOS_ST)
- x-cookie(ORACLE_SMP_CHRONOS_LT)
- x-cookie(ORACLE_SMP_CHRONOS_GL)
- cs(Referer)
- cs(User-Agent)
- x-esi-info

If the default formats are not suitable for your configuration, you can specify the fields that you require. Table 12-5 describes the supported fields. Fields prefixed with x or r are proprietary to OracleAS Web Cache.

Table 12-5 Access Log Fields

Field	Description
`bytes`	Content length of the request
`c-ip`	IP address of the browser
`cached`	Integer that specifies cache status. Cache status is reported as one of the following: `0` specifies a cache miss. Equivalent to `M`, `U`, `G`, and `N` output of `x-cache` field. `1` specifies a cache hit of a stale document. Equivalent to `S` output of `x-cache` field. `2` specifies a cache hit. Equivalent to `H` output of `x-cache` field.
`cs(``header_name``)`	HTTP request header sent from the browser See Also: "cs(header_name) and sc(header_name) Access Log Fields"
`cs-bytes`	Bytes received from the browser
`cs-method`	Browser-to-OracleAS Web Cache HTTP request method
`cs-uri`	Browser-to-OracleAS Web Cache URI
`cs-uri-query`	Browser-to-OracleAS Web Cache query portion of URI, omitting the stem
`cs-uri_stem`	Browser-to-OracleAS Web Cache stem portion of URI, omitting the query
`date`	Date the transaction completed, in the following format: `dd/Mon/yyyy`
`r-ip`	IP address and port number of origin server. For a cache cluster, this field displays the IP and port number of a peer cache in the cache cluster. The information is displayed in the following format: `IP_address:port`
`r-time-taken`	Time, in seconds (including microseconds), that OracleAS Web Cache spent communicating with the origin server or peer cache. The time is the duration between the following two points of time: The time immediately before OracleAS Web Cache sent the first byte of the request to the origin server or peer cache. The time immediately after receiving the last byte of the response from the origin server or peer cache. This field is particularly helpful in providing time information for End-User Performance Monitoring.
`s-ip`	IP address of OracleAS Web Cache computer
`sc(``header_name``)`	HTTP response header sent from OracleAS Web Cache to the browser See Also: "cs(header_name) and sc(header_name) Access Log Fields"
`sc-status`	OracleAS Web Cache-to-browser HTTP status code: 1xx range messages are informational 2xx range messages indicate success 3xx range messages indicate redirection, that is, further action must be taken to complete the request 4xx range messages indicate a client error 5xx range messages indicate a OracleAS Web Cache error See Also: `http://www.ietf.org/rfc/rfc2616.txt` for further information about HTTP status codes
`time`	Time at which the response from OracleAS Web Cache completed. The time is displayed in the following format: `hh:mm:ss`
`time-taken`	Amount of time taken, in seconds (including microseconds), for the transaction to complete
`x-auth-id`	User name of a basic HTTP authentication request
`x-cache`	Cache status. Cache status is reported as one of the following: `H` specifies a cache hit `S` specifies a cache hit of a stale document `U` specifies a cache update of a stale document `G` specifies a cache update of a document that was marked for removal but still physically resides in the cache `M` specifies a cacheable cache miss `N` specifies a non-cacheable cache miss
x-cache-detail	Diagnostic information, in the following format: {`ESI_processing_type`}{`cache_request_type`} [;max-age=`expiration_time``[+``removal_time``]`;age=`document_age`] `ESI_processing_type` can be one of the following: `T` specifies that the document is an ESI template `F` specifies that the document is an ESI fragment Empty specifies that the response does not require ESI processing `cache_request_type` can be one of the following: `H` specifies a cache hit `S` specifies a cache hit of a stale document `U` specifies a cache update of a stale document `G` specifies a cache update of a document that was marked for removal but still physically resides in the cache `M` specifies a cacheable cache miss `N` specifies a non-cacheable cache miss `max_age` specifies the time, in seconds, to expire the document, and optionally, the time, in seconds, to remove the document from the cache after the expiration time. `max_age` does not appear if the `cache_request_type` is `N`. `age` shows how long, in seconds, the document has been in the cache. `age` does not appear if the document is non-cacheable. Example: `H;max-age=60+30;age=50` `H` means that this request resulted in cache hit `max-age=60+30` means that the document is to expire in 60 seconds from population and to be removed from the cache 30 seconds from the expiration. This provides a total of 90 seconds from population. `age=50` means that 50 seconds have passed since population of the cache, meaning there is 10 seconds to expiration and 40 seconds to removal
`x-cache-key`	Cache key value, in the following format: "`cache_key`"
`x-clf-date`	Date that the response from OracleAS Web Cache completed, in the following format: `dd/Mon/yyyy:hh:mm:ss [+GMT]`
`x-cluster`	Single character that specifies the status of a cache cluster. The character is reported as one of the following: `T` specifies a request to a cache cluster member `F` specifies a request from a cache cluster member `O` specifies a request for owned content `D` specifies a request for on-demand content
`x-cookie(``cookie_name``)`	Cookie value from browser request.
`x-date-start`	Date before OracleAS Web Cache received the first byte of the request, in the following format: `yyyy-mm-dd`
`x-date-end`	Date when OracleAS Web Cache sent the last byte of the response, in the following format: `yyyy-mm-dd`
`x-ecid`	ID of the specified in `Oracle-ECID` request header, in the following format: `"``ID``,` `sequence_number``"` See Also: "Oracle-ECID Request-Header Field"
`x-esi-info`	ESI fragment log message from the `log` element of `<esi:environment>` or `<esi:include` tags. It uses the following format: `"``ESI_log_message``"` The log message only displays for requested ESI fragments in the `access_log_file``.fragment` file. When a request ESI fragment is not configured with the `log` element, this field displays as a hyphen (-)
`x-log-id`	Login user name of the client. OracleAS Web Cache is unable to obtain the value for this field. Therefore, OracleAS Web Cache displays a hyphen (`-)` in the output when this field is set.
`x-os-name`	Origin server or cache cluster member that OracleAS Web Cache is forwarding the request, in the following format: `host:port`
`x-os-timeout`	Single character that specifies if the origin server timed out on a request. The character is reported as one of the following: `0` specifies that the origin server did not timeout `1` specifies that the origin server did timeout. An output of `1` can indicate a problem with the origin server itself.
`x-protocol`	Protocol and version from browser request, in the following format: `protocol/version`
`x-req-line`	Request line, in the following format: `"``HTTP_request_method URI protocol/version``"` Example: `"GET /cache.htm HTTP/1.1"`
`x-req-type`	Request type. Request type is reported as one of the following: `B` specifies that the request is from the browser `C` specifies that the request is from another cache cluster member `H` specifies that the request is from another cache cluster or an OracleAS Web Cache that is not a member of the current cache cluster `F` specifies that the request is for an ESI fragment
`x-time-delay`	Time, in seconds (including microseconds), that OracleAS Web Cache spent communicating with the origin server or peer cache. The time is the duration between the following two points of time: The time immediately before OracleAS Web Cache received the first byte of the request The time immediately before OracleAS Web Cache sent the first byte of the request to the origin server or peer cache. This field is particularly helpful in providing time information for End-User Performance Monitoring.
`x-time-end`	Time that OracleAS Web Cache sent the last byte of the response, in the following format: `hh:mm:ss:ssssss`
`x-time-handshake`	The difference between the time the browser initiates a new connection and the time at which OracleAS Web Cache receives the first byte of the HTTP request. Note: Select this field only if instructed by Oracle Support Services.
`x-time-reqrecvlatency`	The difference between the time at which OracleAS Web Cache receives the first and last byte of the HTTP request. This field indicates the time in reading the browser requests. Note: Select this field only if instructed by Oracle Support Services.
`x-time-reqsendlatency`	The difference between the time at which OracleAS Web Cache sends the first and last byte of the HTTP request to the origin server. This field indicates the time taken in sending the request to the origin server. Note: Select this field only if instructed by Oracle Support Services.
`x-time-resprecvlatency`	The difference between the time at which OracleAS Web Cache receives the first and last byte of the HTTP response from the origin server. This field indicates the time taken in receiving the response from the origin server. Note: Select this field only if instructed by Oracle Support Services.
`x-time-respsendlatency`	The difference between the time at which OracleAS Web Cache sends the first and last byte of the HTTP response to the browser. This field indicates the time taken in sending the response to the client. Note: Select this field only if instructed by Oracle Support Services.
`x-time-reqblocked`	The difference between when a request was blocked and unblocked because of garbage collection. If a request has already been sent to the origin server by OracleAS Web Cache to update an existing document, OracleAS Web Cache blocks all subsequent requests. Note: Select this field only if instructed by Oracle Support Services.
`x-time-reqqueued`	The difference between when a request is queued and dequeued for the origin server. This field indicates the time a request spends in OracleAS Web Cache backend queue for an origin server (due to the maximum origin server capacity being reached) before the request is sent to the origin server for processing. Note: Select this field only if instructed by Oracle Support Services.
`x-time-start`	Time before OracleAS Web Cache received the first byte of the request, in the following format: `hh:mm:ss:ssssss`

12.3.1.1 cs(header_name) and sc(header_name) Access Log Fields

Table 12-6 lists examples of HTTP/1.1 headers that can be used for the cs(header_name) and sc(header_name) fields. This table lists only some of the possible headers. It is not an exhaustive list.

Table 12-6 Examples of HTTP/1.1 Header Fields

*cs(header_name) Field*	*sc(header_name) Field*
`Accept`	`Cache-Control`
`Authorization`	`Content-Encoding`
`Connection`	`Content-Language`
`Date`	`Content-Length`
`Host`	`Content-Type`
`Referer`	`Date`
`Cache-Control`	`ETag`
`Content-Encoding`	`Expires`
`Content-Language`	`Last-Modified`
`Content-Length`	`Pragma`
`Content-Type`	`Server`
`If-None-Match`	`Transfer-Encoding`
`If-Modified-Since`	`Via`
`Last-Modified`
`Pragma`
`Range`
`TE`
`User-Agent`
`Via`

Table 12-7 lists examples of cookie-related headers that can be used for the cs(header_name) and sc(header_name) fields.

Table 12-7 Supported Cookie-Related Header Fields

*cs(header_name) Field*	*sc(header_name) Field*
`Cookie`	`Set-Cookie`

Table 12-8 lists examples of OracleAS Web Cache headers that can be used for the cs(header_name) and sc(header_name) fields.

Table 12-8 Supported OracleAS Web Cache Header Fields

*cs(header_name) Field*	*sc(header_name) Field*
`Surrogate-Capability`	`Surrogate-Control`

12.3.2 Configuring Access Logs

To establish access log configuration settings:

Start OracleAS Web Cache Manager.

See Also:
"Starting OracleAS Web Cache Manager"
In the navigator frame, select Logging and Diagnostics > Access Logs.

The Access Logs page appears.
Specify cache-specific access log settings:
1. From the Cache-Specific Access Log Configuration table, select a cache, and then click Edit Selected.
  
  The Edit Cache-Specific Access Log Configuration dialog box appears.
2. In the Directory field, enter the directory in which to write access logs.
  
  The default is $ORACLE_HOME/webcache/logs on UNIX and ORACLE_HOME\webcache\logs on Windows.
3. In the Enabled field, select Yes to enable logging, or No to disable logging.
4. In the Buffering field, select Enabled to enable buffered logging or Disabled to disable buffered logging.
  
  With buffered logging, OracleAS Web Cache writes to the access log after the buffer is full. The buffer size is set 2048 bytes. When the limit is reached, OracleAS Web Cache writes buffered events to the access log file.
  
  Oracle Corporation recommends disabling buffering when you need to see the access log results immediately.
5. In the Flush Interval field, set the frequency at which buffered information is written to the access log file.
  
  The default is 10 seconds. When the interval is reached, OracleAS Web Cache writes buffered information to the access log file. Even if the buffer is not full, the access log is updated at least every 10 seconds. Oracle Corporation recommends not changing the default, unless you need to lower the interval to see results more frequently.
6. Click Submit.
Specify site-specific log settings:
1. From the Site-Specific Access Log Configuration table, click Add.
  
  The Edit/Add Site Specific Access Log Configuration dialog box appears.
2. From the For Site list, select the Web site for which to specify access log settings.
3. In the File Name field, enter a name for the access log file.
  
  The default file name is access_log.
4. In the Enabled field, select Yes to enable logging for the site or No to disable logging for the site.
  
  Site-specific logging only takes effect if logging is enabled for the cache. If you select Yes, ensure that Yes is also selected for the cache in Step 3 c.
5. In the ESI Fragment Requests field, select Log to log the ESI fragment log messages from the log element of <esi:environment> or <esi:include in the access_log_file.fragment file.
  
  If the x-esi-info field is selected, select Log to log the events to the access_log_file.fragment file. If the x-esi-info field is not selected, select Don’t Log. The x-esi-info field is automatically selected if the Format Style is WCLF.
6. From the Format Style list, select an access log format.
  
  See Also:
  "Format of the Access Log Files" for a description of the CLF, Combined, and WCLF formats
7. From the Rollover Policy list, select a rollover policy to specify how often you want to change the frequency at which OracleAS Web Cache saves current log information to access_log_file.yyyymmdd and writes new log information to the current access log file.
  
  For high-volume sites, select a policy with a high frequency.
8. Click Submit.
If the CLF, Combined, and WCLF formats are not suitable for your environment, create a log format that is:
1. From the User-Defined Log Formats table, click Add.
  
  The Edit/Add User-Defined Access Log Format dialog box displays.
2. In the Format Name field, enter a unique name for the format.
3. From the Separator list, select the separator to use for separating access log fields.
4. In Print XLF Directive field, select Yes to include XLF directive information at the top of the access log or No to not include directive information in the access log.
  
  Directive information typically consists of version and date information. For example:
```
#Version: 1.0
#Date: 12-Dec-2002 00:00:00
#Fields: c-ip x-auth-id x-clf-date cs(Host x-req-line sc-status bytes
```
  See Also:
  http://www.w3.org/TR/WD-logfile.html for further information about XLF directives
5. In the XLF Fields section, select an access log field name from the Field name list.
  
  See Also:
  Table 12-5 for a listing of the supported access logs fields
6. If you selected field cs(header_name), sc(header_name), or x-cookie(cookie_name), then enter the header or cookie name in the Header/Cookie name field.
  
  See Also:
  Table 12-6, Table 12-7, and Table 12-8 for a description of the headers allowed for cs(header_name) and sc(header_name)
7. Click Add.
8. Perform Steps e and f for each format you want in the access log, and then use the Move Up and Move Down buttons to order the fields. The order in which fields are entered determines the order in which the fields are logged.
9. Click Submit.

Optionally, modify or create rollover policies:

Select an existing policy and click Edit Selected to modify and existing rollover policy, or click Add to create a new policy.

The Edit/Add Access Log Rollover Policy dialog box appears.
In the Rollover Policy Name field, enter the a unique name for the rollover policy.

In Rollover Policy section, select Weekly, Daily, Hourly, or Never to specify how often you want OracleAS Web Cache to save current log information to access_log_file.yyyymmdd and write new log information to the current access log file.

Table 12-9 describes additional configuration instructions for Weekly, Daily, and Hourly.

Table 12-9 Configuring Weekly, Daily and Hourly Rollover Policies

Policy	To configure:
Weekly	Select a day of the week. Use the Time fields to enter the hour and minutes. From the Time Style list, select either Local or GMT.
Daily	From the Rollover times - each day list, select a time. If the time you require does not exist, use the Time fields to enter the hour and minutes, and then click Add. From the Time Style list, select either Local or GMT.
Hourly	From the Rollover times - minutes past the hour list, select a time. If the time you require does not exist, use the Minutes past the hour field to enter the number of minutes, and then click Add. From the Time Style list, select either Local or GMT.

If you have a high-volume site, create a daily or hourly policy.

See Also:

"Rolling Over Event and Access Logs " for instructions on immediately rolling over log files

Click Submit.

Apply changes and restart OracleAS Web Cache:
1. In the OracleAS Web Cache Manager main window, choose Apply Changes.
2. In the Cache Operations page, choose Restart.

Logging Cache Cluster Peer Requests

By default, peer requests between two members of a cache cluster are not logged in the access log. Only client requests to the cluster are logged. Peer request logging can be enabled for individual cache cluster members by adding the ACCESSLOGIGNOREPEERREQUEST attribute to the MISCELLANEOUS element in the internal.xml configuration file.

The valid values for this attribute are: YES and NO.

The following example shows the MISCELLANEOUS element with peer-to-peer logging enabled:

<MISCELLANEOUS ACCESSLOGIGNOREPEERREQUEST="NO"/>

12.3.3 Analyzing an Access Log File

The following code shows an excerpt of an access log file:

10.10.150.35 - - [19/Jul/2003:10:27:42 -0500] "GET /~user/personal.htm HTTP/1.1" 200 2438 
10.10.150.35 - - [19/Jul/2003:10:27:54 -0500] "GET /~user/personal.htm?UserName=Bob HTTP/1.1" 200 2438 
10.10.150.35 - - [19/Jul/2003:10:47:30 -0500] "GET /~user/count.sh HTTP/1.1" 403 289 
10.10.150.35 - - [19/Jul/2003:10:47:34 -0500] "GET /~user/sbin/count.sh HTTP/1.1" 200 321

In the first line of the output, the fields have the following meaning:

10.10.150.35 is the browser’s IP address (c-ip)
[19/Jul/2003:10:27:42 -0500] is the date ([x-clf-date])
"GET /~user/personal.htm HTTP/1.1" is the request line ("x-req-line")
200 is the HTTP status code (sc-status)
2438 is the size of the document sent (bytes)

12.3.4 Access Log Examples

This section contains the following access log examples:

Example: Access Log with Reload Entries
Example: Access Log with Status Code 404 Entry
Example: Access Log in Combined Format
Example: Access Log with Site Information
Example: Access Log with ESI Diagnostic Information
Example: Access Log with ESI Log Information

Except where noted otherwise, the access log examples use the CLF format:

c-ip x-log-id x-auth-id x-clf-date x-req-line sc-status bytes

Example: Access Log with Reload Entries

The following shows an access log excerpt in which there are two Web browser reloads, followed by two shift reloads, and two more reloads:

10.10.150.35 - - [19/Nov/2002:11:04:24 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [19/Nov/2002:11:04:26 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [19/Nov/2002:11:29:24 -0500] "GET /cache.htm HTTP/1.1" 304 0 
10.10.150.35 - - [19/Nov/2002:11:29:25 -0500] "GET /cache.htm HTTP/1.1" 304 0 
10.10.150.35 - - [19/Nov/2002:11:29:30 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [19/Nov/2002:11:29:35 -0500] "GET /cache.htm HTTP/1.1" 200 250

The third and forth entries return an HTTP status code of 304, indicating that document has not been modified and does not need to be returned again.

Example: Access Log with Status Code 404 Entry

The following shows an access log excerpt in which OracleAS Web Cache cannot find any objects matching the requested URL /ows-img/chalk.jpg. This error is indicated by HTTP status code 404.

10.10.150.35 - - [19/Nov/2002:10:49:44 -0500] "GET /pls/coe/find_via_post HTTP/1.1" 200 1119 
10.10.150.35 - - [19/Nov/2002:10:49:44 -0500] "GET /ows-img/chalk.jpg HTTP/1.1" 404 284

Example: Access Log in Combined Format

The following shows an access log excerpt in which the combined format is specified:

c-ip x-log-id x-auth-id x-clf-date x-req-line sc-status bytes cs(Referer)
 cs(User-Agent)

148.87.1.180 - - [25/Jun/2003:20:09:47 +0000] "GET /manual/sections.html HTTP/1.1" 200 -1 "http://www.company.com:80/manual/mod/directive-dict.html#Syntax" "Mozilla/4.78 [ja] (Win98; U)"
148.87.1.180 - - [25/Jun/2003:20:09:50 +0000] "GET /manual/mod/core.html HTTP/1.1" 200 -1 "http://www.company.com:80/manual/sections.html" "Mozilla/4.78 [ja] (Win98; U)"
148.87.1.180 - - [25/Jun/2003:20:10:06 +0000] "GET / HTTP/1.1" 200 -1 - "Mozilla/4.78 [ja] (Win98; U)"
148.87.1.180 - - [25/Jun/2003:20:10:14 +0000] "GET /manual/LICENSE HTTP/1.1" 200 -1 "http://www.company.com:80/manual/index.html" "Mozilla/4.78 [ja] (Win98; U)"

Example: Access Log with Site Information

The following shows an access log excerpt in which the following fields are specified:

c-ip x-auth-id x-clf-date cs(Host) x-req-line sc-status bytes

cs(Host) displays the output of Host request-header field, which specifies the site information. In this example, requests are sent to OracleAS Web Cache for site www.company.com:80.

148.87.1.180 - [25/Jun/2003:20:05:51 +0000] "www.company.com:80" "GET / HTTP/1.1" 200 -1
148.87.1.180 - [25/Jun/2003:20:05:56 +0000] "www.company.com:80" "GET /manual/index.html HTTP/1.1" 200 -1
148.87.1.180 - [25/Jun/2003:20:05:59 +0000] "www.company.com:80" "GET /manual/upgrading_to_1_3.html HTTP/1.1" 200 -1
148.87.1.180 - [25/Jun/2003:20:06:02 +0000] "www.company2.com:80" "GET /manual/mod/mod_dir.html HTTP/1.1" 200 -1
148.87.1.180 - [25/Jun/2003:20:06:05 +0000] "www.company2.com:80" "GET /manual/mod/directive-dict.html HTTP/1.1" 200 -1

Example: Access Log with ESI Diagnostic Information

The following shows an access log excerpt in which the following fields are specified:

c-ip x-clf-date x-req-line sc-status bytes x-cache-detail

x-cache-detail displays diagnostic information. In the following example:

T means that this request is for an ESI template
H means that this request resulted in cache hit
max-age=10+15 means that the document is to expire in 10 seconds from population and to be removed from the cache 15 seconds from the expiration. This provides a total of 25 seconds from population.
age=0 means that 0 seconds have passed since population of the cache, meaning there is 10 seconds to expiration and 15 seconds to removal

[16/Jan/2003:02:35:37 +0000] "GET /cgi-bin/esi-headers.sh?err1.htm HTTP/1.0" 200 42 TM;max-age=10+15;age=0

Example: Access Log with ESI Log Information

The following shows an access log excerpt in which the following fields are specified:

c-ip x-clf-date x-req-line sc-status bytes x-esi-info

x-esi-info displays log information from the log element of <esi:environment> or <esi:include tags.

[16/Jan/2003:03:03:35 +0000] "GET /b.html HTTP/1.0" 200 4 "This is a sample fragment."

12 Logging Events, Diagnostics, and Access Information

12.1 Evaluating Event Logs

12.1.1 Format of the Event Log File

12.1.2 Configuring Event Logs

12.1.3 Event Log Examples

12.2 Displaying Diagnostic and Event Log Information in the HTML Body or Server-Response Header Field

12.3 Evaluating Access Logs

12.3.1 Format of the Access Log Files

12.3.1.1 cs(header_name) and sc(header_name) Access Log Fields

12.3.2 Configuring Access Logs

12.3.3 Analyzing an Access Log File

12.3.4 Access Log Examples

12.3.1 Format of the Access Log File s