Configure API Gateway tracing

Overview

By default, the API Gateway outputs tracing and debugging information to record information about its execution. For example, this includes details such as services starting or stopping, and messages sent through the API Gateway. This information then can be used by API Gateway administrators and developers for diagnostics and debugging purposes, and is useful when contacting Oracle Support. You can view and search the contents of API Gateway tracing in the following locations:

  • Logs > Trace view in API Gateway Manager

  • Trace files in the following location:

    • Admin Node Manager: <install-dir>/trace

    • API Gateway instance: <install-dir>/groups/<group-id>/<instance-id>/trace

    • API Gateway Analytics: <install-dir>/trace

  • Windows or UNIX console window for the running server

The Logs view in API Gateway Manager enables you to view and search the contents of the API Gateway trace log, transaction log, access log, and domain audit log. This topic explains how to configure the trace log only. For more details, see Configure API Gateway logging and events.

View API Gateway trace files

Each time the API Gateway starts up, by default, it outputs a trace file to the API Gateway trace directory (for example, INSTALL_DIR\groups\group-2\server1\trace). The following example shows an extract from a default API Gateway trace file:

INFO    15/Jun/2012:09:54:01.047 [1b10] Realtime monitoring enabled
INFO    15/Jun/2012:09:54:01.060 [1b10] Storing metrics in database disabled
INFO    15/Jun/2012:09:54:03.229 [1b10] cert store configured
INFO    15/Jun/2012:09:54:03.248 [1b10] keypairs configured
...

The trace file output takes the following format:

TraceLevel   Timestamp [thread-id] TraceMessage

For example, the first line in the above extract is described as follows:

TraceLevel INFO
Timestamp 15/Jun/2012:09:54:01.047

(day:hours:minutes: seconds:milliseconds)
Thread-id [1b10]
TraceMessage Realtime monitoring enabled


Set API Gateway trace levels

The possible trace levels in order of least to most verbose output are as follows:

  • FATAL

  • ERROR

  • INFO

  • DEBUG

  • DATA

where FATAL is the least verbose and DATA is the most verbose. The default trace level is INFO.

Set trace levels

You can set the trace level using the following different approaches:

Startup trace When the Admin Node Manager is starting up, it gets its trace level from the tracelevel attribute of the SystemSettings element in /system/conf/nodemanager.xml. You can set the trace level in this file if you need to diagnose boot up issues.
Default Settings trace When the API Gateway has started, it reads its trace level from the Default Settings for the API Gateway instance. To set this trace level in the Policy Studio, click the Server Settings node in the Policy Studio tree, select a Trace level from the drop-down list.
Interface level trace You can configure an HTTP/HTTPS interface with a different trace level to that specified in the Default Settings. For example, the default API Gateway management port (8090) has a trace level set to ERROR to ensure it is not too verbose. To configure the trace level for an interface in the Policy Studio, right-click the interface under the Listeners node, select Edit, and select a Trace level from the drop-down list.
Dynamic trace You can also change dynamic API Gateway trace levels on-the-fly in API Gateway Manager. For more details, see the section called “Configure trace and log settings”.


Configure API Gateway trace files

By default, trace files are named servername_timestamp.trc (for example, server1_20130118160212.trc). You can configure the settings for trace file output in INSTALL_DIR/system/conf/trace.xml, which is included by INSTALL_DIR/system/conf/nodemanager.xml. By default, trace.xml contains the following setting:

<FileRolloverTrace maxfiles="500" filename="%s_%Y%m%d%H%M%S.trc"/>

This setting means that the API Gateway writes Node Manager trace output to nodemanageronhostname_timestamp.trc (for example, nodemanageron127.0.0.1_20130118160212.trc) in the trace directory of the API Gateway installation. And the maximum number of files that the trace directory can contain is 500.

FileRolloverTrace Attributes

The FileRolloverTrace element can contain the following attributes:

filename File name used for trace output. Defaults to the tracecomponent attribute read from the SystemSettings element.
directory Directory where the trace file is written. Defaults to INSTALL_DIR/trace when not specified.
maxlen Maximum size of the trace file in bytes before it rolls over to a new file. Defaults to 16777216 (16 MB).
maxfiles Maximum number of files that the trace directory contains for this filename. Defaults to the maximum integer value (2147483647).
rollDaily Whether the trace file is rolled at the start of the day. Defaults to true.


The following setting shows example attributes:

<FileRolloverTrace maxfiles="5" maxlen="10485760" rollDaily="true" 
    directory="/mydir/log/trace" filename="myserver.trc"/>

This setting means that the API Gateway writes trace output to myserver.trc in the /mydir/log/trace directory, and rolls the trace files over at the start of each day. The maximum number of files that this directory can contain is 5, and the maximum trace file size is 10 MB.

Writing Trace Output to Syslog

On UNIX and Linux, you can send API Gateway trace output to syslog. In your INSTALL_DIR/system/conf/trace.xml file, add a SyslogTrace element, and specify a facility. For example:

<SyslogTrace facility="local0"/>

Run trace at DEBUG level

When troubleshooting, it can be useful to set to the trace level to DEBUG for more verbose output. When running a trace at DEBUG level, the API Gateway outputs the status of every policy and filter that it processes into the trace file.

Debugging a Filter

The trace output for a specific filter takes the following format:

Filter name {
    Trace for the filter is indented
    to the following point to make it clear
    to identify output from the filter
} status, in x milliseconds

The status is 0, 1, or 2, depending if the filter failed, succeeded, or aborted. For example, the result of an WS-Security Username Token filter running successfully is as follows:

DEBUG 12:43:59:093 [11a4] run filter [WS-Security Username Token] {
DEBUG 12:43:59:093 [11a4]    WsUsernameTokenFilter.invoke: Verify username and password
DEBUG 12:43:59:093 [11a4]    WsAuthN.getWSUsernameTokenDetails: 
                             Get token from actor=current actor
DEBUG 12:43:59:093 [11a4]    Version handler -  creating a new ws block
DEBUG 12:43:59:108 [11a4]    Version handler - adding the ws element to the wsnodelist
DEBUG 12:43:59:108 [11a4]    Version handler -  number of ws blocks found:1
DEBUG 12:43:59:124 [11a4]    No timestamp passed in WS block, no need to check timestamp
DEBUG 12:43:59:139 [11a4]    WsAuthN.getWSUsernameTokenDetails: Check <Created> element 
                             in token. Value=2010-08-06T11:43:43Z
DEBUG 12:43:59:139 [11a4]    WS Nonce TimeStamp Max Size is 1000 and wsNonces cache is 4
DEBUG 12:43:59:139 [11a4]    Add WS nonce for key [joe:2010-08-06T11:43:43Z]. 
                             New cache size [5].
DEBUG 12:43:59:155 [11a4]    WsBasicAuthN.getUsername: Getting username
DEBUG 12:43:59:171 [11a4]    WS-Security UsernameToken authN via CLEAR password
DEBUG 12:43:59:171 [11a4]    VordelRepository.checkCredentials: username=joe
DEBUG 12:43:59:186 [11a4] } = 1, in 62 milliseconds

Debug a policy

The trace output for a policy shows it running with all its contained filters, and takes the following format:

policy Name {
    Filter 1{
        Trace for the filter
    } status, in x milliseconds
    Filter 2{
        Trace for the filter
    } status, in x milliseconds
} 

For example, the following extract shows a policy called when running a simple service:

DEBUG ... run circuit "/axis/services/urn:cominfo"...
DEBUG ... run filter [Service Handler for 'ComInfoServiceService'] {
DEBUG ...   Set the service name to be ComInfoServiceService
DEBUG ...   Web Service context already set to ComInfoServiceService
DEBUG ...   close content stream
DEBUG ...   Calling the Operation Processor Chain [1. Request from Client]...
DEBUG ...   run filter [1. Request from Client] {
DEBUG ...      run filter [Before Operation-specific Policy] {
DEBUG ...         run circuit "WS-Security UsernameToken AuthN"...
DEBUG ...           run filter [WS-Security Username Token] {
                     ...
DEBUG ...           } = 1, in 62 milliseconds
DEBUG ...           ..."WS-Security UsernameToken AuthN" complete.
DEBUG ...       } = 1, in 74 milliseconds  
...

Debug at startup

When running a startup trace with a DEBUG level set in the SystemSettings, the API Gateway outputs the configuration that it is loading. This can often help to debug any incorrectly configured items at start up, for example:

DEBUG 14:38:54:206 [1ee0] configure loadable module type RemoteHost, load order = 500000
DEBUG 14:38:54:206 [1ee0] RemoteHost {
DEBUG 14:38:54:206 [1ee0]     ESPK: 1035
DEBUG 14:38:54:206 [1ee0]     ParentPK: 113
DEBUG 14:38:54:206 [1ee0]     Key Fields:
DEBUG 14:38:54:206 [1ee0]         name: {csdwmp3308.wellsfargo.com}
DEBUG 14:38:54:206 [1ee0]         port: {7010}
DEBUG 14:38:54:221 [1ee0]     Fields:
DEBUG 14:38:54:221 [1ee0]         maxConnections: {128}
DEBUG 14:38:54:268 [1ee0]         turnMode: {off}
DEBUG 14:38:54:268 [1ee0]         inputBufSize: {8192}
DEBUG 14:38:54:268 [1ee0]         includeContentLengthRequest: {0}
DEBUG 14:38:54:268 [1ee0]         idletimeout: {15000}
DEBUG 14:38:54:268 [1ee0]         activetimeout: {30000}
DEBUG 14:38:54:268 [1ee0]         forceHTTP10: {0}
DEBUG 14:38:54:268 [1ee0]         turnProtocol: {http}
DEBUG 14:38:54:268 [1ee0]         includeContentLengthResponse: {0}
DEBUG 14:38:54:268 [1ee0]         addressCacheTime: {300000}
DEBUG 14:38:54:268 [1ee0]         outputBufSize: {8192}
DEBUG 14:38:54:268 [1ee0]         sessionCacheSize: {32}
DEBUG 14:38:54:268 [1ee0]         _version: {1}
DEBUG 14:38:54:268 [1ee0]         loadorder: {500000}
DEBUG 14:38:54:268 [1ee0]         class: {com.vordel.dwe.NativeModule}
DEBUG 14:38:54:268 [1ee0] }

For details on setting trace levels and running a startup trace, see the section called “Set API Gateway trace levels”.

Run trace at DATA level

When the trace level is set to DATA, the API Gateway writes the contents of the messages that it receives and sends to the trace file. This enables you to see what messages the API Gateway has received and sent (for example, to reassemble a received or sent message).

[Note] Note

On Windows, you can not rely on the console output because it truncates large messages.

Searching by thread

Every HTTP request handled by the API Gateway is processed in its own thread, and threads can be reused when an HTTP transaction is complete. You can see what has happened to a message in the API Gateway by following the trace by thread ID. Because multiple messages can be processed by the API Gateway at the same time, it is useful to eliminate threads that you are not interested in by searching for items that only match the thread you want.

You can do this using the search feature in the API Gateway Manager Logs view. Enter the thread you wish to search for in the Only show lines with text textbox, and click Refresh. Alternatively, you can do this on the command line using vi by specifying the thread ID as a pattern to search for in the trace file. In this example, the thread ID is 145c:

:g!/145c/d

The following example shows the DATA trace when a message is sent by the API Gateway (message starts with snd): >

DATA 17:45:35:718 [145c]  snd 1495: <POST /axis/services/urn:cominfo HTTP/
     1.1Connection: closeContent-Length: 1295User-Agent: VordelSOAPAction: 
     ""Via: 1.0 devsupport2 (Vordel)Host: devsupport2:7070Content-Type: 
     text/xml<?xml version="1.0" encoding="UTF-8" standalone="no"?>
     <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" 
     xmlns:xsd="http://www.w3.org/2001/XMLSchema" 
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
     <soap:Header>
       <wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/
       oasis-200401-wss-wssecurity-secext-1.0.xsd"> 
       <wsse:UsernameToken xmlns:wsu="http://docs.oasis-open.org/wss/2004/01/
         oasis-200401-wss-wssecurity-utility-1.0.xsd" 
         wsu:Id="Id-00000128d05aca81-00000000009d04dc-10">
              <wsse:Username>joeuser</wsse:Username>
              <wsse:Nonce EncodingType="utf-8">
                  gmP9GCjoe+YIuK1einlENA==
              </wsse:Nonce>
              <wsse:Password Type="http://docs.oasis-open.org/wss/2004/01/
              oasis-200401-wss-username-token-profile-1.0#PasswordText"> 
                    joepwd
              </wsse:Password>
              <wsu:Created>2010-05-25T16:45:30Z</wsu:Created>
         </wsse:UsernameToken>
         </wsse:Security>
      </soap:Header>
      <soap:Body>
          <ns1:getInfo xmlns:ns1="http://stock.samples">
              <symbol xsi:type="xsd:string">CSCO</symbol>
              <info xsi:type="xsd:string">address</info>
          </ns1:getInfo>
      </soap:Body>
    </soap:Envelope>
>

The following example shows the DATA trace when a message is received by the API Gateway (message starts with rcv):

DATA 17:45:35:734 [145c]  rcv 557: <HTTP/1.0 200 OKSet-Cookie: 8Set-Cookie2: 
     8Content-Type: 
     text/xml; charset=utf-8<?xml version="1.0" encoding="UTF-8"?>
     <soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" 
     xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/
     XMLSchema-instance">
     <soapenv:Body>
        <ns1:getInfoResponse soapenv:encodingStyle="http://schemas.xmlsoap.org/soap/
        encoding/" xmlns:ns1="http://stock.samples">
            <getInfoReturn xsi:type="xsd:string">San Jose, CA</getInfoReturn>
        </ns1:getInfoResponse>
      </soapenv:Body>
     </soapenv:Envelope>
>

If you want to see what has been received by the API Gateway on this thread, run the following command:

:g!/145c] rcv/d

All snd and rcv trace statements start and end with < and > respectively. If you are assembling a message by hand from the DATA trace, remember to remove characters. In addition, the sending and/or receiving of a single message may span multiple trace statements.

Integrate trace output with Apache log4J

Apache log4j is included on the API Gateway classpath. This is because some third-party products that the API Gateway interoperates with require log4j. The configuration for log4j is found in the API Gateway INSTALL_DIR/system/lib directory in the log4j.properties file.

For example, to specify that the log4j appender sends output to the API Gateway trace file, add the following setting to your log4j.properties file:

log4j.rootLogger=DEBUG, A1, Vordel
log4j.appender.Vordel=com.vordel.trace.VordelTraceAppender

Get help with API Gateway

Context-sensitive help is available from the Policy Studio screens. Click the Help button on any screen to display the relevant help page for that screen. If you require further information or assistance, please contact the Oracle Support team.

Details for Oracle Support

It is important to include as much information as possible when contacting the Oracle Support team. This helps to diagnose and solve the problem in a more efficient manner. The following information should be included with any Support query:

  • Name and version of the product (for example, Oracle API Gateway 11.1.2.3.0).

  • Details of patches that were applied to the product, if any.

  • Platform on which the product is running.

  • A clear (step-by-step) description of the problem or query.

  • If you have encountered an error, the error message should be included in the email. It is also useful to include any relevant trace files from the /trace directory of your product installation, preferably with the trace level set to DEBUG.