9 Logging

The logging feature of Oracle Web Cache enables you to troubleshoot difficulties you might have in execution and use of Oracle Web Cache and associated processes.

This chapter includes the following topics:

9.1 Introduction to Event Logs

Oracle Web Cache records event and error information in event logs. An event log entry can help you determine what objects have been inserted in the cache and alert you to any cache-related issues. By default, Oracle Web Cache collects all event log messages associated with each request in memory. If the most severe message in the request is at or above the selected verbosity level, Oracle Web Cache writes all the messages related to the request to the event log at once. Oracle Web Cache groups the messages for the request together in the log file for easier diagnosis.

By default, the event log has a file name of event_log for the Oracle Web Cache and Oracle Diagnostic Logging (ODL) text formats and log.xml for the ODL XML format. Oracle Web Cache stores logs files in the following directories:

(UNIX) ORACLE_INSTANCE/diagnostics/logs/WebCache/<webcache_name>
(Windows) ORACLE_INSTANCE\diagnostics\logs\WebCache\<webcache_name>

This section includes the following topics:

9.1.1 Event Logging Formats

When you configure settings for event logs, select the logging format:

9.1.1.1 Oracle Diagnostics Logging Text and XML Formats

The Oracle Diagnostic Logging (ODL) format provides a common format for all diagnostic messages and log files, and a mechanism for correlating the diagnostic messages from various components across Oracle Fusion Middleware.

You can select ODL Text to create a text file or ODL XML to create an XML file.

The format of the ODL Text format follows:

[TSTZ_ORIGINATING] [MSG_TYPE:MSG_ID] [MODULE_ID;MSG_LEVEL] [MODULE_ID] [ECID] MSG_TEXT

Table 9-4 describes the fields for the ODL Text format.

Table 9-1 ODL Text Message Fields

Fields Description

TSTZ_ORIGINATING

The date and time when the message was generated. Time is either displayed in local or Greenwich Mean Time.

MSG_TYPE

The type of message. Possible values are NOTIFICATION, WARNING, TRACE, and DEBUG.

MSG_LEVEL

The message level, represented by an integer value that qualifies the message type. Possible values are from 1 (highest severity) through 32 (lowest severity).

MSG_ID

The ID that uniquely identifies the message within the component. The ID consists of a prefix that represents the component, followed by a dash, then a 5-digit number. For example: WXE-08513.

The Oracle Fusion Middleware Error Messages Reference describes the messages in further detail.

MODULE_ID

The ID of the module that originated the message. If the component is a single module, the component ID is listed for this attribute.

ECID

The Execution Context ID (ECID), which is a global unique identifier of the execution of a particular request in which the originating component participates. You can use the ECID to correlate error messages from different components.

See Also: Section 9.1.1.4 for more information about the Oracle-ECID request header

MSG_TEXT

The text of the error message.


The following shows an event log excerpt with the ODL Text format:

[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-08513] [logging] [ecid: ] Cache server process ID 11679 is starting up.
[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-09612] [main] [ecid: ] Oracle Web Cache 11g (11.1.1)
[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-13002] [config] [ecid: ] Maximum allowed incoming connections are 700
[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-09446] [stats] [ecid: ] Statistics initialization commencing.
[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-09441] [stats] [ecid: ] DMS enabled
[2008-11-04T05:55:35-05:00] [webcache] [NOTIFICATION:1] [WXE-09447] [stats] [ecid: ] Statistics initialization complete.
[2008-11-04T05:55:36-05:00] [webcache] [NOTIFICATION:1] [WXE-12209] [cluster] [ecid: ] A 1 node cluster successfully initialized
[2008-11-04T05:55:36-05:00] [webcache] [NOTIFICATION:1] [WXE-09614] [main] [ecid: ] The following Oracle Web Cache internal files are pre-populated to the cache: [[/host:port/_oracle_http_server_webcache_static_.html]]

Table 9-2 describes the fields for the ODL XML format.

Table 9-2 ODL XML Message Fields

Fields Description

TSTZ_ORIGINATING

The date and time when the message was generated. Time is either displayed in local or Greenwich Mean Time.

COMPONENT_ID

The ID of the component that originated the message.

MSG_ID

The ID that uniquely identifies the message within the component. The ID consists of a prefix that represents the component, followed by a dash, then a 5-digit number. For example: WXE-08513.

MSG_TYPE

The type of message. Possible values are NOTIFICATION, WARNING, TRACE, and DEBUG.

MSG_LEVEL

The message level, represented by an integer value that qualifies the message type. Possible values are from 1 (highest severity) through 32 (lowest severity).

HOST_ID

The name of the host where the message originated.

HOST_NWADDR

T he network address of the host where the message originated.

MODULE_ID

The ID of the module that originated the message. If the component is a single module, the component ID is listed for this attribute.

ECID

The Execution Context ID (ECID), which is a global unique identifier of the execution of a particular request in which the originating component participates. You can use the ECID to correlate error messages from different components.

See Also: Section 9.1.1.4 for more information about the Oracle-ECID request header

MSG_TEXT

The text of the error message.


The ODL XML Format provides additional fields, such as the following shows an event log excerpt for the ODL XML format:

<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.0116-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>8513</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>logging</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>Cache server process ID 13176 is starting up.
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.0117-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9612</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>main</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>Oracle Web Cache 11g (11.1.1)
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.0118-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>13002</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>config</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>Maximum allowed incoming connections are 700
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.0191-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9446</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>stats</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>Statistics initialization commencing.
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.0265-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9438</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>stats</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>The statistics persistent repository is being reset by new configuration
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.1556-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9441</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>stats</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>DMS enabled
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.1559-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9447</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>stats</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>Statistics initialization complete.
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:14.5912-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>12209</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>cluster</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>A 1 node cluster successfully initialized
</MSG_TEXT>
  </PAYLOAD>
</MESSAGE>
<MESSAGE>
  <HEADER>
    <TSTZ_ORIGINATING>2008-11-04T06:07:20.8036-05:00</TSTZ_ORIGINATING>
    <COMPONENT_ID>WXE</COMPONENT_ID>
    <MSG_ID>9614</MSG_ID>
    <MSG_TYPE TYPE="NOTIFICATION"></MSG_TYPE>
    <MSG_LEVEL>1</MSG_LEVEL>
    <HOST_ID>host</HOST_ID>
    <HOST_NWADDR>10.10.150.35</HOST_NWADDR>
    <MODULE_ID>main</MODULE_ID>
  </HEADER>
  <CORRELATION_DATA>
    <EXEC_CONTEXT_ID>
      <UNIQUE_ID>-</UNIQUE_ID>
      <SEQ>0</SEQ>
    </EXEC_CONTEXT_ID>
  </CORRELATION_DATA>
  <PAYLOAD>
    <MSG_TEXT>The following Oracle Web Cache internal files are pre-populated to the cache: [[/host:port/_oracle_http_server_webcache_static_.html]]
</MSG_TEXT>  </PAYLOAD></MESSAGE>

For more information about the ODL format, see:

9.1.1.2 Oracle Web Cache Classic Format

The Oracle Web Cache log format is intended for customers who prefer the traditional log format provided by Oracle Web Cache in previous releases.

The format of the Oracle Web Cache format follows:

[TIMESTAMP] [MSG_TYPE MSG_ID] [ECID] MSG_TEXT

Table 9-3 describes the fields for Oracle Web Cache format.

Table 9-3 Oracle Web Cache Message Fields

Fields Description

TIMESTAMP

The date and time when the message was generated. Time is either displayed in local or Greenwich Mean Time.

MSG_TYPE

The type of message. Possible values are NOTIFICATION, WARNING, TRACE, and DEBUG.

MSG_ID

The ID that uniquely identifies the message within the component. The ID consists of a 5-digit number. For example: 08513.

ECID

The Execution Context ID (ECID), which is a global unique identifier of the execution of a particular request in which the originating component participates. You can use the ECID to correlate error messages from different components.

See Also: Section 9.1.1.4 for more information about the Oracle-ECID request header

MSG_TEXT

The text of the error message.


For example:

[04/Nov/2008:06:11:53 -0500] [notification 08513] Cache server process ID 13466is starting up.
[04/Nov/2008:06:11:53 -0500] [notification 09612] [ecid: -] Oracle Web Cache 11g (11.1.1)
[04/Nov/2008:06:11:53 -0500] [notification 13002] [ecid: -] Maximum allowed incoming connections are 700
[04/Nov/2008:06:11:53 -0500] [notification 09446] [ecid: -] Statistics initialization commencing.
[04/Nov/2008:06:11:53 -0500] [notification 09438] [ecid: -] The statistics persistent repository is being reset by new configuration
[04/Nov/2008:06:11:53 -0500] [notification 09441] [ecid: -] DMS enabled
[04/Nov/2008:06:11:53 -0500] [notification 09447] [ecid: -] Statistics initialization complete.
[04/Nov/2008:06:11:54 -0500] [notification 12209] [ecid: -] A 1 node cluster successfully initialized
[04/Nov/2008:06:11:54 -0500] [notification 09614] [ecid: -] The following Oracle Web Cache internal files are pre-populated to the cache: [[/host:port/_oracle_http_server_webcache_static_.html]]

9.1.1.3 Request Details in Message 9720

Oracle Web Cache displays the request detail format in message 09720 when you enable option Include Request Details in the event log messages. This message is logged the first time an event is logged for a request with the following additional request details, including the client IP address, site name of the request and URL of the request.

Table 9-4 describes the fields for the request detail format.

Table 9-4 Request Details

Fields Description

[detail]

Request detail event

[client: IP_address]

IP address of the client that made the request

[host: site]

Site name of the request

[url: URL]

URL of the request


For example:

[2008-11-20T23:27:32Z] [webcache] [TRACE:1] [WXE-09720] [io] [ecid: 15431471130,0] [req-info: ] [client: 140.87.8.166] [host: -] [url: /images/image1k.bmp]
[2008-11-20T23:27:31Z] [webcache] [TRACE:1] [WXE-11331] [frontend] [ecid: 15431471130,0] Request matches configured site: www.company.com:80
[2008-11-20T23:27:31Z] [webcache] [TRACE:1] [WXE-11414] [population] [ecid: 15431471130,0] Basic cache key is composed with sitename www.company.com:80, URI /images/image1k.bmp, method GET, post body -.
[2008-11-20T23:27:31Z] [webcache] [TRACE:1] [WXE-11304] [frontend] [ecid: 15431471130,0] Cache miss 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.

9.1.1.4 About the Oracle-ECID Request-Header Field

The Oracle-ECID request header is used to track requests as they move through the Oracle Fusion Middleware architecture. This information is especially useful for diagnostic purposes. Because Oracle Web Cache is the initial receiver of client requests, it sets the request header before forwarding a cache miss to an origin server. The Oracle-ECID request header takes the following format:

Oracle-ECID: request_id, sequence_number

In the format, request_id is a 64-bit unique integer for the request, and sequence_number is the hop number of the request as it passes through Oracle Fusion Middleware. Oracle Web Cache typically assigns an initial sequence number of 0 to a request. As a request passes from Oracle Web Cache to other Oracle Fusion Middleware components, the request ID remains constant, but the sequence number increments with each hop.

You can configure Oracle Web Cache to log the request ID and sequence number from the Oracle-ECID request header in the event and access logs. To display the Oracle-ECID request header in the event logs, you enable the Include Request Details option, and select the x-ecid field for the access logs. The x-ecid field is provided by default with the Enhanced CLF (ECLF), Enhanced Combined Log Format, and End-User Performance Monitoring Format. Additionally, you can configure Oracle HTTP Server to log the Oracle-ECID request header information, enabling you to correlate events at different Oracle Fusion Middleware stops for the same request.

Oracle Web Cache also includes Oracle-ECID request header information whenever you configure to display diagnostic information in the Server response-header field or the HTML response body.

See Section 8.8 or further information about configuring diagnostic output in the Server response-header field or the HTTP response message that includes Oracle-ECID information

9.1.2 Event Log Examples

This section contains the following event log examples:

9.1.2.1 Example: Event Log with Unsuccessful Startup Entries

The following shows an event log excerpt with unsuccessful startup events. Oracle Web Cache cannot listen on port 7777, because it is in use. These errors can occur if Oracle Web Cache is running and listening on that port or another application is using that port.

[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-08513] [logging] [ecid: ] Cache server process ID 2427 is starting up. 
[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-09612] [main]  [ecid: ] Oracle Web Cache 11g (11.1.1) 
[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-13002] [config] [ecid: ] Maximum allowed incoming connections are 700 
[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-09446] [stats]  [ecid: ] Statistics initialization commencing. 
[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-09438] [stats]  [ecid: ] The statistics persistent repository is being reset by new configuration [2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-09441] [stats]  [ecid: ] DMS enabled 
[2008-11-04T16:37:24-05:00] [webcache] [NOTIFICATION:1] [WXE-09447] [stats]  [ecid: ] Statistics initialization complete. 
[2008-11-04T16:37:25-05:00] [webcache] [TRACE:1] [WXE-11366] [frontend] [ecid: ] A client connection to listening port 7777 is dropped. 
[2008-11-04T16:37:25-05:00] [webcache] [TRACE:1] [WXE-11380] [frontend] [ecid: ] Network failure during client listen client listen (details: internal=failure system=2) 
[2008-11-04T16:37:25-05:00] [webcache] [ERROR:1] [WXE-09707] [main] [ecid: ] Failed to start the server. 
[2008-11-04T16:37:25-05:00] [webcache] [ERROR:1] [WXE-09609] [main] [ecid: ] The server process could not initialize. 
[2008-11-04T16:37:25-05:00] [webcache] [NOTIFICATION:1] [WXE-09610] [main]  [ecid: ] The server is exiting. 
[2008-11-04T16:37:25-05:00] [webcache] [NOTIFICATION:1] [WXE-08514] [logging] [ecid: ] Cache server process ID 2427 is shutting down.

9.1.2.2 Example: Event Log with Shutdown Entries

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

[2008-11-04T16:19:58-05:00] [webcache] [NOTIFICATION:1] [WXE-09703] [main]  [ecid: ] Stop Issued. The program will shut down after all accepted requests are served, or a timeout occurs. 
[2008-11-04T16:21:29-05:00] [webcache] [NOTIFICATION:1] [WXE-09610] [main]  [ecid: ] The server is exiting.

9.1.2.3 Example: Event Log with Cache Miss and Cache Hit Entries

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

[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11331] [frontend] [ecid: 5415484202,0] Request matches configured site: www.company.com:80
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11414] [population] [ecid: 5415484202,0] Basic cache key is composed with sitename www.company.com:80, URI /invalidate1/tcal_fct_invalidate_basic_2.html, method GET, post body -.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11304] [frontend] [ecid: 5415484202,0] Cache miss request.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11224] [os] [ecid: 5415484202,0] Site localhost:8888 matches site-to-server mapping www.company.com:80.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11227] [os] [ecid: 5415484202,0] Initial Request is routed to origin server host-server:8080 using load balancing.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11403] [population] [ecid: 5415484202,0]  begin cacheability decision for url: www.company.com:80/invalidate1/tcal_fct_invalidate_basic_2.html
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11481] [population] [ecid: 5415484202,0] Request/Response matches caching rule with URL expression "^/invalidate1/.*\.h.*$".
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-13736] [compression] [ecid: 5415484202,0] Compression is disabled because the browser does not support compression.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11446] [population] [ecid: 5415484202,0] URL which will be cached is: www.company.com:80/invalidate1/tcal_fct_invalidate_basic_2.html
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11415] [population] [ecid: 5415484202,0] Final cache key is composed sitename www.company.com:80, URI /invalidate1/tcal_fct_invalidate_basic_2.html, method GET, post body -, multiversion -, compressed no.
[2008-11-04T15:37:02-05:00] [webcache] [TRACE:1] [WXE-11088] [backend] [ecid: 5415484202,0] Following URL is now in cache: www.company.com:80/invalidate1/tcal_fct_invalidate_basic_2.html

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

[2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-09720] [frontend] [ecid: 417732382502,0] [req-info: ] [client: 127.0.0.1] [host: www.company.com:80] [url: /x-oracle-cache-invalidate] 
[2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-11331] [frontend] [ecid: 417732382502,0] Request matches configured site: localhost:8888 [2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-11414] [population] [ecid: 417732382502,0] Basic cache key is composed with sitename www.company.com:80, URI /invalidate1/tcal_fct_invalidate_basic_5.html, method GET, post body -. 
[2008-11-04T15:37:39-05:00] [webcache] [NOTIFICATION:1] [WXE-11707] [invalidation] [ecid: 417732382502,0] Object with URL '/invalidate1/tcal_fct_invalidate_basic_5.html' is successfully invalidated. 
[2008-11-04T15:37:39-05:00] [webcache] [NOTIFICATION:1] [WXE-11748] [invalidation] [ecid: 417732382502,0] Invalidation with INFO 'about-ttl' has returned with status 'SUCCESS'; number of objects invalidated: '1'.

9.1.2.4 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 object /invalidation1/tcal_fct_invalidate_basic_5.html.

[2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-09720] [frontend] [ecid: 417732382502,0] [req-info: ] [client: 10.10.150.35] [host: host:port] [url: /x-oracle-cache-invalidate] 
[2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-11331] [frontend] [ecid: 417732382502,0] Request matches configured site: www.company.com:80 
[2008-11-04T15:37:39-05:00] [webcache] [TRACE:1] [WXE-11414] [population] [ecid: 417732382502,0] Basic cache key is composed with sitename localhost:8888, URI /invalidate1/tcal_fct_invalidate_basic_5.html, method GET, post body -. 
[2008-11-04T15:37:39-05:00] [webcache] [NOTIFICATION:1] [WXE-11707] [invalidation] [ecid: 417732382502,0] Object with URL '/invalidate1/tcal_fct_invalidate_basic_5.html' is successfully invalidated. 
[2008-11-04T15:37:39-05:00] [webcache] [NOTIFICATION:1] [WXE-11748] [invalidation] [ecid: 417732382502,0] Invalidation with INFO 'about-ttl' has returned with status 'SUCCESS'; number of objects invalidated: '1'.

9.1.2.5 Example: Analyzing ESI Events

The following provides an example of the messages in the event log for an ESI fragment for a cache miss. The messages in the event log report information about:

  • How Oracle Web Cache processes ESI in the template

  • How ESI processing loads an ESI fragment

  • After the fragment is loaded, how the caching decision for an ESI fragment is formed. It includes information regarding the reason the fragment is cached or not cached.

In the following examples, TRACE:1 messages are for the verbosity=TRACE level and TRACE:32 messages are for the verbosity=DEBUG level. Setting verbosity to DEBUG includes TRACE, NOTIFICATION, WARNING, and ERROR level messages. TRACE includes NOTIFICATION, WARNING, and ERROR, but not DEBUG.

You do not see the following log messages shown in the following example unless you have the set the event_log verbosity level to DEBUG:

[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11952] [esi] [ecid: 211577120190,0] Start processing ESI document www.company.com:80/cgi-bin/esi-headers.sh?/esi/esi-headers.html&localhost:8888, nesting level 1 [2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11331] [frontend] [ecid: 211577120190,0] Request matches configured site: www.company.com:80 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11953] [esi] [ecid: 211577120190,0] In ESI template www.company.com:80/cgi-bin/esi-headers.sh?/esi/esi-headers.html&localhost:8888, the fragment's site name and URL has been discovered as www.company.com:80 and /esi/include0.html [2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11304] [frontend] [ecid: 211577120190,0] Cache miss request. 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11224] [os] [ecid: 211577120190,0] Site www.company.com:80 matches site-to-server mapping www.company.com:80. 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11227] [os] [ecid: 211577120190,0] Initial Request is routed to origin server stadk61.us.oracle.com:8080 using load balancing. 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11403] [population] [ecid: 211577120190,0]  [[ begin cacheability decision for  url: www.company.com:80/esi/include0.html ]] 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11481] [population] [ecid: 211577120190,0] Request/Response matches caching rule with URL expression "/*". [2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11446] [population] [ecid: 211577120190,0]  [[ URL which will be cached is: www.company.com:80/esi/include0.html ]] 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11415] [population] [ecid: 211577120190,0] Final cache key is composed sitename www.company.com:80, URI /esi/include0.html, method GET, post body -, multiversion -, compressed no. 
[2008-11-04T16:29:14-05:00] [webcache] [TRACE:1] [WXE-11088] [backend] [ecid: 211577120190,0]  [[ Following URL is now in cache: www.company.com:80/esi/include0.html ]]

9.2 Introduction to Access Logs

Oracle Web Cache records information about the received HTTP and HTTPS requests in access logs. Each Web site Web site defined in Oracle Web Cache can have its own access log. By default, the access log has a file name of access_log and is stored in the following directories:

(UNIX) ORACLE_INSTANCE/diagnostics/logs/WebCache/<webcache_name>
(Windows) ORACLE_INSTANCE\diagnostics\logs\WebCache\<webcache_name>

This section includes the following topics:

9.2.1 Access Log Formats

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 standard Extended LogFile Format (XLF). By default, Oracle Web Cache provides support for the following access log formats:

9.2.1.1 Common Log 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

9.2.1.2 Enhanced CLF (ECLF)

This format uses many of the CLF fields and includes the x-ecid field for tracking the request ID and sequence number specified in Oracle-ECID request header:

  • c-ip

  • x-log-id

  • x-auth-id

  • x-clf-date

  • x-req-line

  • sc-status

  • bytes

  • x-ecid

9.2.1.3 Combined Log Format

This format provides support for the CLF fields with the addition of the cs(Referer) and cs(User-Agent) fields:

  • c-ip

  • x-log-id

  • x-auth-id

  • x-clf-date

  • x-req-line

  • sc-status

  • bytes

  • cs(Referer)

  • cs(User-Agent)

Select this format when you must determine what kind of browser is sending the request, and where the browser was visiting before the request was forwarded to Oracle Web Cache.

9.2.1.4 Enhanced Combined Log Format

This format uses many of the Combined Log Format fields and includes the x-ecid field for tracking the ID of the specified in Oracle-ECID request header:

  • c-ip

  • x-log-id

  • x-auth-id

  • x-clf-date

  • x-req-line

  • sc-status

  • bytes

  • cs(Referer)

  • cs(User-Agent)

  • x-ecid

9.2.1.5 End-User Performance Monitoring Format

This format provides support for the following fields intended for end-user performance monitoring of 10g 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)

  • x-glcookie-set

  • cs(Referer)

  • cs(User-Agent)

  • x-esi-info

  • x-conn-abrt

  • sc(Content-Type)

9.2.2 Access Log Fields

If the default formats are not suitable for your environment, you can create custom log formats by specifying the fields that you require. Table 9-5 describes the supported fields. Fields prefixed with x or r are proprietary to Oracle Web Cache.

Table 9-5 Access Log Fields

Field Description

bytes

Content length of the request

c-ip

IP address of the client

cached

Integer that specifies cache status. Cache status is reported as 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 object. 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 client

See Also: "cs(header_name) and sc(header_name) Access Log Fields"

cs-bytes

Bytes received from the client

cs-method

Client-to-Oracle Web Cache HTTP request method

cs-uri

Client-to-Oracle Web Cache URI

cs-uri-query

Client-to-Oracle Web Cache query portion of URI, omitting the stem

cs-uri_stem

Client-to-Oracle 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 Oracle 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 Oracle 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 Oracle Web Cache computer

sc(header_name)

HTTP response header sent from Oracle Web Cache to the client

See Also: "cs(header_name) and sc(header_name) Access Log Fields"

sc-status

Oracle Web Cache-to-client 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 Oracle 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 Oracle 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 the following:

  • H specifies a cache hit

  • S specifies a cache hit of a stale object

  • U specifies a cache update of a stale object

  • G specifies a cache update of an object 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=object_age]

ESI_processing_type is:

  • T specifies that the object is an ESI template

  • F specifies that the object is an ESI fragment

  • Empty specifies that the response does not require ESI processing

cache_request_type is:

  • H specifies a cache hit

  • S specifies a cache hit of a stale object

  • U specifies a cache update of a stale object

  • G specifies a cache update of an object 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 object, and optionally, the time, in seconds, to remove the object 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 object has been in the cache. age does not appear if the object 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 object 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 Oracle 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 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 client browser request.

x-conn-abrt

Single character that specifies the whether a connection was terminated before a response was completed. This field is intended for end-user performance monitoring.

  • C specifies that the connection was terminated by the client before Oracle Web Cache could complete a response.

  • O specifies that the connection was terminated by the origin server before it could complete a response to Oracle Web Cache.

  • N specifies the response was completed without the connection being terminated.

x-date-start

Date before Oracle Web Cache received the first byte of the request, in the following format:

yyyy-mm-dd

x-date-end

Date when Oracle 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:

"request_ID, sequence_number"

See Also: Section 9.1.1.4 for further information about the Oracle-ECID request header

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-glcookie-set

Boolean character that specifies whether Oracle Web Cache created the ORACLE_SMP_CHRONOS_GL cookie and sent as a response to the client browser a Set-Cookie:ORACLE_SMP_CHRONOS_GL response header field. This field is intended for end-user performance monitoring to track transactions.

  • Y specifies that Oracle Web Cache set the ORACLE_SMP_CHRONOS_GL cookie. Y also marks the beginning of a transaction for the client. All subsequent traffic from the browser send a Cookie request-header field set with the ORACLE_SMP_CHRONOS_GL cookie received in the Oracle Web Cache response.

  • N specifies that Oracle Web Cache did not create the cookie. This result can occur because the cookie is already set.

x-log-id

Login user name of the client. Oracle Web Cache cannot obtain the value for this field. Therefore, Oracle Web Cache displays a hyphen (-) in the output when this field is set.

x-os-name

Origin server or cache cluster member that Oracle 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 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 client 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 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 Oracle 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 Oracle 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 Oracle Web Cache received the first byte of the request

  • The time immediately before Oracle 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 Oracle Web Cache sent the last byte of the response, in the following format:

hh:mm:ss:ssssss

x-time-handshake

The difference between the times the client initiates a new connection and the time at which Oracle 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 times Oracle 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 times Oracle 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 times Oracle 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 times Oracle 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 due to a cache update. If a request has been sent to the origin server by Oracle Web Cache to update an existing object, Oracle Web Cache blocks all subsequent requests.

Note: Select this field only if instructed by Oracle Support.

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 Oracle Web Cache back-end 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.

x-time-start

Time before Oracle Web Cache received the first byte of the request, in the following format:

hh:mm:ss:ssssss


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

Table 9-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 possible headers. It is not an exhaustive list.

Table 9-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 9-7 lists examples of cookie-related headers that can be used for the cs(header_name) and sc(header_name) fields.

Table 9-7 Supported Cookie-Related Header Fields

cs(header_name) Field sc(header_name) Field

Cookie

Set-Cookie


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

Table 9-8 Supported Oracle Web Cache Header Fields

cs(header_name) Field sc(header_name) Field

Surrogate-Capability

Surrogate-Control


9.2.3 Access Log Examples

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

10.10.150.35 - - [25/Jul/2005:10:27:42 -0500] "GET /~user/personal.htm HTTP/1.1" 200 2438 
10.10.150.35 - - [25/Jul/2005:10:27:54 -0500] "GET /~user/personal.htm?UserName=Bob HTTP/1.1" 200 2438 
10.10.150.35 - - [25/Jul/2005:10:47:30 -0500] "GET /~user/count.sh HTTP/1.1" 403 289 
10.10.150.35 - - [25/Jul/2005: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)

  • [25/Jul/2005: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 object sent (bytes)

In addition, this section contains the following access log examples:

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

9.2.3.1 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 - - [25/Jul/2005:11:04:24 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [25/Jul/2005:11:04:26 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [25/Jul/2005:11:29:24 -0500] "GET /cache.htm HTTP/1.1" 304 0 
10.10.150.35 - - [25/Jul/2005:11:29:25 -0500] "GET /cache.htm HTTP/1.1" 304 0 
10.10.150.35 - - [25/Jul/2005:11:29:30 -0500] "GET /cache.htm HTTP/1.1" 200 250 
10.10.150.35 - - [25/Jul/2005: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 object has not been modified and does not need to be returned again.

9.2.3.2 Example: Access Log with Status Code 404 Entry

The following shows an access log excerpt in which Oracle 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 - - [25/Jul/2005:10:49:44 -0500] "GET /pls/coe/find_via_post HTTP/1.1" 200 1119 
10.10.150.35 - - [25/Jul/2005:10:49:44 -0500] "GET /ows-img/chalk.jpg HTTP/1.1" 404 284 

9.2.3.3 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)

10.10.150.35 - - [25/Jul/2005: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)"
10.10.150.35 - - [25/Jul/2005: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)"
10.10.150.35 - - [25/Jul/2005:20:10:06 +0000] "GET / HTTP/1.1" 200 -1 - "Mozilla/4.78 [ja] (Win98; U)"
10.10.150.35 - - [25/Jul/2005: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)"

9.2.3.4 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 Oracle Web Cache for site www.company.com:80.

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

9.2.3.5 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 object 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

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

9.2.3.6 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.

[25/Jul/2005:03:03:35 +0000] "GET /b.html HTTP/1.0" 200 4 "This is a sample fragment."

9.3 Configuring Event Logs

To configure event log settings:

  1. Navigate to the Web Cache Home page in Fusion Middleware Control. See Section 2.6.2.

  2. From the Web Cache menu, select Administration and then Event Logs.

    The Event Log Configuration page displays.

  3. Specify the following settings for each cache in the Cache-Specific Settings table:

    1. In the Directory field, enter the directory in which to write event logs.

      By default, the event log is stored in the following directories:

      (UNIX) ORACLE_INSTANCE/diagnostics/logs/WebCache/<webcache_name>
      (Windows) ORACLE_INSTANCE\diagnostics\logs\WebCache\<webcache_name>
      
    2. Click Enable Buffering? to enable buffered logging; deselect the check box to disable buffered logging.

      With buffered logging, Oracle Web Cache stores log messages in memory. Oracle Web Cache writes them out in bulk to the event log when the buffer size or the flush interval is reached. Buffered logging increases performance by reducing the number of disk I/O operations.

      If the Oracle Web Cache server shuts down unexpectedly, buffered log messages may be lost.

      Oracle recommends disabling buffering to see the event log results immediately.

    3. If buffering is enabled, in the Flush Interval field, enter the interval, in seconds, when Oracle Web Cache writes contents of the buffer to the event log file.

      The default is 10 seconds. When the interval is reached, Oracle Web Cache writes buffered information to the event log file. Even if the buffer is not full, Oracle Web Cache updates the event log. Oracle recommends not changing the default, unless you want to lower the interval to see results more frequently.

      A value of 0 specifies that Oracle Web Cache will only flush the buffered event log when the specified buffer size has been exceeded.

    4. If buffering is enabled, in the Buffer Size field, enter the size of the buffer, expressed in characters.

      The default is 2048 characters. You can specify a maximum value of 32,768 characters.

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

      Table 9-9 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 configuration.

      • Site resolution

      • Site-to-server mappings route to the correct origin servers

      • Compression

      • Session binding

      • Caching rules

      • ESI processing

      Debug

      Provides detailed events for troubleshooting. This level is intended for Oracle Support Services.


  4. Set the global event log settings in the Global Event Log Configuration section:

    1. In the File Name field, enter a name for the event log file.

      The default file name is event_log.

    2. From the File Format list, select the log format.

      See Section 9.1.1 for further information about the formats.

    3. From the Time Style list, select either Local or GMT (Greenwich Mean Time) to modify the format of the time stamp style associated with entries in the event log file.

      Note:

      Oracle 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 operating system. As such, Oracle Web Cache has no mechanism to improve the performance of the conversion process.
    4. Click Request-Based Logging to enable request-based logging.

      With request-based logging, Oracle Web Cache collects all event log messages associated with each request in memory. If the most severe message in the request is at or above the selected verbosity level, Oracle Web Cache writes all the messages related to the request to the event log at once. Oracle Web Cache groups the messages for the request together in the log file for easier diagnosis. For example, if verbosity is set to Notification, and Oracle Web Cache encounters an error at the Trace or Debug level, Oracle Web Cache writes all of the event log messages for the request to the event log.

      Select Disabled to view results as they happen, especially when the verbosity is set to a level higher than Notification.

    5. In Include Request Details, select Yes to enable Oracle Web Cache to write the information from the Oracle-ECID request header, or select No to not write request information to the event log. See Section 9.1.1.2 for further information about how request details are logged.

      Select No if either of the following conditions apply:

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

      • Oracle Web Cache is running in a standalone environment without Oracle HTTP Server.

  5. Specify a rollover policy:

    1. In the Rollover By Time section, click Edit.

      The Edit Rollover Policy dialog displays.

      You can use the rollover options in combination. For example, you can use both Rollover by Time and Rollover by Size or both Retention by Size and Retention by Time. Oracle Web Cache performs rollover based on whichever is reached first.

    2. From the Rollover by Time list, select Never, Hourly, Daily, or Weekly to specify how often you want Oracle Web Cache to save current log information to event_log_file.yyyymmddhhmm and write future log information to a new log file with the configured log file name.

      If you have a high-volume site, select Daily or Hourly.

    3. In the Scheduled Time field, for Hourly, Daily, and Weekly, enter a new time in the left-hand side fields and menus and add it to the schedule by clicking Add. Table 9-10 describes specific configuration instructions for Hourly, Daily, and Weekly.

      Table 9-10 Configuring Rollover By Time

      Policy To configure:

      Hourly

      1. Enter a value in the field to reflect the minutes after the hour. The default 0 means at the start of the hour.

      2. Click Add.

      3. From the Time Style list, select either Local or GMT (Greenwich Mean Time).

      Daily

      1. Enter a value in the hours and minutes fields. The default 0 means at the start of the day.

      2. Click Add.

      3. From the Time Style list, select either Local or GMT.

      Weekly

      1. Add a time by selecting a day of the week, and entering values in the hours and minutes fields. The default 0 means at the start of the week.

      2. Click Add.

      3. From the Time Style list, select either Local or GMT (Greenwich Mean Time).


      To remove a time from the schedule list, select the time, and then click Remove. The value moves to the left list, where you can modify it.

      See Section 9.8 for instructions on immediately rolling over log files.

    4. In the Rollover by Size field, enter the maximum size of the log file size at which rollover occurs. Specify 0 for unlimited size.

    5. In the Retention by Time field, specify how long to keep log files before purging the oldest ones.

      In the Every field, enter the quantity and from the list of Hours, Days, Weeks, Months, Years, select the duration. A quantity of 0 means unlimited time, which means Oracle Web Cache does not retain files based on time.

    6. In the Retention by Size field, enter the total size of all log files before purging oldest ones. Specify 0 for unlimited size.

      This value must be larger than the value you specify for the Rollover Size field.

      If neither Retention by Time or Retention by Size is set, then log files can grow without limits. The log files could end up consuming all available space on the disk where this file is located.

    7. Click OK.

  6. Click Apply and restart Oracle Web Cache. See Section 2.13.

9.4 Configuring Access Logs

To configure access log settings:

  1. Navigate to the Web Cache Home page in Fusion Middleware Control. See Section 2.6.2.

  2. From the Web Cache menu, select Administration and then Access Logs.

    The Access Log Configuration page displays.

  3. Specify the following settings for each cache in the Cache-Specific Settings table:

    1. In the Directory field, enter the directory in which to write access logs.

      By default, the event log is stored in the following directories:

      (UNIX) ORACLE_INSTANCE/diagnostics/logs/WebCache/<webcache_name>
      (Windows) ORACLE_INSTANCE\diagnostics\logs\WebCache\<webcache_name>
      
    2. Click Enable Logging? to enable logging; deselect to disable logging.

    3. Click Enable Buffering? to enable buffered logging; deselect the check box to disable buffered logging.

      With buffered logging, Oracle Web Cache stores log messages in memory. Oracle Web Cache writes them out in bulk to the access log when the buffer size or the flush interval is reached. The buffer size is set to 2048 bytes. Buffered logging increases performance by reducing the number of disk I/O operations.

      If the Oracle Web Cache server shuts down unexpectedly, buffered log messages may be lost.

      Oracle recommends disabling buffering to view access log results immediately.

    4. If buffering is enabled, in the Flush Interval field, enter the interval, in seconds, when Oracle Web Cache writes contents of the buffer to the access log file.

      The default is 10 seconds. When the interval is reached, Oracle Web Cache writes buffered information to the access log file. Even if the buffer is not full, Oracle Web Cache updates the access log. Oracle recommends not changing the default, unless you want to lower the interval to see results more frequently.

      A value of 0 specifies that Oracle Web Cache will only flush the buffered access log when the specified buffer size has been exceeded.

  4. Specify the following settings for each site in the Site-Specific Settings table:

    1. If you want to apply the settings from the Default Settings row to this site, click Use Default for all Sites Settings. Deselect this checkbox to provide site-specific overrides in the other fields.

    2. In the File Name field, enter a name for the access log file.

      The default file name is access_log.

    3. Click Enable Logging to enable logging for the site; deselect to disable logging for the site.

      Site-specific logging only takes effect if logging is enabled for the cache. If you enable this option, ensure that it is also selected for the cache in Step 3b.

    4. Select Log ESI Fragment Requests? 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 to log the events to the access_log_file.fragment file. The x-esi-info field is automatically selected if the Format Style is End-User Performance Monitoring Format. If the x-esi-info field is not selected, select Don't Log.

    5. From the Format Style list, select an access log format.

      See Section 9.2.1 for a description of the default formats and Section 9.5 to create a customized style for your environment.

    6. From the Rollover Policy list, select a rollover policy to specify how often you want to change the frequency at which Oracle Web Cache saves current log information to access_log_file.yyyymmddhhmm and writes future log information to a new log file with the configured log file name.

      For high-volume sites, select a policy with a high frequency.

      See Section 9.6 to modify an existing policy or create a new rollover policy.

  5. Click Apply and restart Oracle Web Cache. See Section 2.13.

9.5 Creating a Customized Access Log Format

If the default formats described in Section 9.2.1 are not suitable for your environment, create a new log format:

  1. Navigate to the Web Cache Home page in Fusion Middleware Control. See Section 2.6.2.

  2. From the Web Cache menu, select Administration and then Access Logs.

    The Access Log Configuration page displays.

  3. Click the Log Formats tab, and click Create.

    The Create Log Format dialog box displays.

  4. In the Format Name field, enter a unique name for the format, keeping the following restrictions in mind:

    • The format name cannot contain any spaces or special characters other than underscore (_).

    • The name must be unique among other format names, rollover policy names, and session names.

  5. From the Separator list, select the separator to use for separating access log fields.

  6. 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, date, and field information. For example:

    #Version: 1.0
    #Date: 12-Jul-2008 00:00:00
    #Fields: c-ip x-auth-id x-clf-date cs(Host x-req-line sc-status bytes
    

    See http://www.w3.org/TR/WD-logfile.html for further information about XLF directives.

  7. In the XLF Fields section, select an access log field name from the Field Name list.

    See Table 9-5 for a listing of the supported access logs fields

  8. If you select cs(header_name or sc 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 Table 9-6, Table 9-7, and Table 9-8 for a description of the headers allowed for cs(header_name) and sc(header_name)

  9. Click Add.

  10. Perform Steps 7 and 9 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.

  11. Click OK to apply changes and return to the Access Log Configuration page.

  12. Click Apply in the Access Log Configuration page to apply this change.

9.6 Creating a Customized Access Log Rollover Policy

To modify an existing rollover policy or create a new rollover policy:

  1. Navigate to the Web Cache Home page in Fusion Middleware Control. See Section 2.6.2.

  2. From the Web Cache menu, select Administration and then Access Logs.

    The Access Log Configuration page displays.

  3. Click the Rollover Policies tab, and click Create.

    The Create Rollover Policy dialog box displays.

    You can use the rollover options in combination. For example, you can use both Rollover by Time and Rollover by Size or both Retention by Size and Retention by Time. Oracle Web Cache performs rollover based on whichever is reached first.

  4. In the Policy Name field, enter a unique name for the rollover policy, keeping the following restrictions in mind:

    • The policy name cannot contain any spaces or special characters other than underscore (_).

    • The name must be unique among other policy names, log format style names, and session names.

  5. In the Rollover by Time section, select Never, Hourly, Daily, Weekly to specify how often you want Oracle Web Cache to save current log information to access_log_file.yyyymmddhhmm and write future log information to a new log file with the configured log file name.

    If you have a high-volume site, select Daily or Hourly.

  6. In the Rollover by Time section, select Never, Hourly, Daily, Weekly to specify how often you want Oracle Web Cache to save current log information to access_log_file.yyyymmddhhmm and write future log information to a new log file with the configured log file name.

    If you have a high-volume site, select Daily or Hourly.

    For Hourly, Daily, and Weekly, enter a new time in the left-hand side fields and menus and add it to the schedule by clicking Add. Table 9-11 describes specific configuration instructions for Hourly, Daily, and Weekly.

    Table 9-11 Configuring Rollover By Time

    Policy To configure:

    Hourly

    1. Enter a value in the field to reflect the minutes after the hour. The default 0 means at the start of the hour.

    2. Click Add.

    3. From the Time Style list, select either Local or GMT (Greenwich Mean Time).

    Daily

    1. Enter a value in the hours and minutes fields. The default 0 means at the start of the day.

    2. Click Add.

    3. From the Time Style list, select either Local or GMT.

    Weekly

    1. Add a time by selecting a day of the week, and entering values in the hours and minutes fields. The default 0 means at the start of the week.

    2. Click Add.

    3. From the Time Style list, select either Local or GMT (Greenwich Mean Time).


    To remove a time from the schedule list, select the time, and then click Remove. The value moves to the left list, where you can modify it.

    See Section 9.8 for instructions on immediately rolling over log files.

  7. In the Rollover by Size field, enter the maximum size of the log file size at which rollover occurs. Specify 0 for unlimited size.

  8. In the Retention by Time field, specify how long to keep log files before purging the oldest ones.

    In the Every field, enter the quantity and from the list of Hours, Days, Weeks, Months, Years, select the duration. A quantity of 0 means unlimited time, which means Oracle Web Cache does not retain files based on time.

  9. In the Retention by Size field, enter the total size of all log files before purging oldest ones. Specify 0 for unlimited size.

    This value must be larger than the value you specify for the Rollover Size field.

    If neither Retention by Time or Retention by Size is set, then log files can grow without limits. The log files could end up consuming all available space on the disk where this file is located.

  10. Click OK to apply changes and return to the Access Log Configuration page.

  11. Click Apply in the Access Log Configuration page to apply this change.

9.7 Viewing Event Logs and Access Logs

To view events logs, use either the Fusion Middleware Control or the WLST listLogs command. See the following documentation resources:

To view access logs, use any text editor.

9.8 Rolling Over Event and Access Logs

In addition to configuring event and access log rollover frequency, you can immediately roll over event and access logs. During the rollover process, Oracle Web Cache saves current information to lot file and writes future log information to a new log file with the configured log file name.

To immediately roll over log files:

  1. Navigate to the Web Cache Home page in Fusion Middleware Control. See Section 2.6.2.

  2. From the Web Cache menu, select Operations and then On Demand Rollover.

9.9 Using Audit Logs

Oracle Web Cache supports the Common Audit Framework for providing a uniform system for administering audits across Oracle Fusion Middleware components. The audit log files generated by Oracle Web Cache processes provide important information that can help you identify and diagnose potential security performance and configuration issues.

Oracle Web Cache records the following events in the audit log:

  • Startup and shutdown events

  • Inter-cache communication events, such as:

    • Authentication or challenge events

    • Subscriber cache insertion to subscriber list (success or failure)

    • Invalid address information from subscriber

    • Remote or subscriber cache authentication event

    • Addition or removal of cluster cache member

  • Request authentication events, such as:

    • Login to Oracle Web Cache ports

    • Denied request due to access control settings or request-filtering rules

    • Identity denied to access cached objects

    • Invalidation in response containing wrong Web site information

    • Client certificate failed

    • SSL connection denied because no client certificate was provided

    • SSL connection denied because client certificate presented was on the CRL

  • Configuration services, such as:

    • Dynamic configuration changes applied

    • SSL handshake failed with the origin server

    • Authentication with the proxy server failed

For more information, see Oracle Fusion Middleware Security Guide for further information about using audit logs.