Bookshelf Home | Contents | Index | PDF     

Transports and Interfaces: Siebel Enterprise Application Integration > Integrating Siebel Business Applications with Java Applications > About the Siebel Resource Adapter >

About JCA Logging

The following improvements have been made to JCA logging in Oracle's Siebel Business Applications version 8.0 and higher:

  • Appending JCA logs to one file, which is found in the working directory of the JVM.

    Previously, each JCA thread would overwrite the same log file over and over again. Now all JCA threads log into one file. When the log file size exceeds 100 MB, it is renamed and a new one is started. For example, test.log is renamed to test_1166581351656.log, where the value is the number of milliseconds since 1970.

  • Proper logging of call stacks for LOG_DEBUG.

    Previously, JCA log events in the LOG_DEBUG level (level 5) logged the call stack, but the call stack was often incomplete and cryptic. Now the call stack is a complete Java call stack.

  • Logging of thread names.

    Previously, the JCA logs did not include the thread name. Now that all threads log to one file, each line contains the thread name. An example of a line in the log file is:

    [SIEBEL INFO] Thread[Servlet.Engine.Transports : 4,5,main] [2010-11-04 15:58:38.058] [SiebelManagedConnection(2137125295)] Cleaning up 0 handles on SiebelManagedConnection(2137125295)

  • New logging in LOG_DETAIL (level 4):
    • When a listener thread is created (logs the host and port):

    [SIEBEL DETAIL] Thread[Thread-1482,5,main] [2010-11-04 16:12:10.139] [] creating socket for listening thread: host=xyz port=9312

    • When the main thread sends a request to the Siebel Server (logs the packet number):

    [SIEBEL DETAIL] Thread[Thread-1482,5,main] [2010-11-04 16:12:56.521] [] set tx=2813

    [SIEBEL DETAIL] Thread[Thread-1482,5,main] [2010-11-04 16:12:56.521] [] wait=1 tx=2813

    • When the main thread receives a response:

    [SIEBEL DETAIL] Thread[Thread-1482,5,main] [2010-11-04 16:12:56.580] [] end loop tx=2813 isDone

    • Before the listener thread reads a packet (logs the number of bytes in the packet):

    [SIEBEL DETAIL] Thread[Thread-54,5,Listener Threads] [2010-11-04 16:12:56.575] [] about to read to bytes: len=1800

    • As the listener thread reads the packet (logs the packet number and number of bytes read thus far):

    [SIEBEL DETAIL] Thread[Thread-54,5,Listener Threads] [2010-11-04 16:12:56.575] [] read some bytes: tx=2813 len=1800 read=1800

  • Logging call stacks when opening and closing a connection to the Siebel Server.

    Previously, the JCA logs for LOG_INFO (level 3) logged the opening and closing of a connection, but did not log the call stack. Now the call stack is logged, for example:

    [SIEBEL INFO] Thread[Servlet.Engine.Transports : 2,5,main] [2010-11-05 07:53:26.078] [SiebelConnection(507473761)] Opening a new connection to Siebel ...

    java.lang.Throwable

    at com.siebel.integration.util.a.trace(Unknown Source)

    at com.siebel.integration.util.SiebelTrace.trace(Unknown Source)

    at com.siebel.integration.jca.cci.SiebelConnection.a(Unknown Source)

    at com.siebel.integration.jca.cci.SiebelConnection.initialize(Unknown Source)

    at com.siebel.integration.jca.cci.SiebelConnection.<init>(Unknown Source)

    at com.siebel.integration.jca.cci.notx.SiebelNoTxConnection.<init>(Unknown Source)

    at com.siebel.integration.jca.spi.notx.SiebelNoTxManagedConnectionFactory
    .createManagedConnection(Unknown Source)

    at com.ibm.ejs.j2c.poolmanager.FreePool
    .createManagedConnectionWithMCWrapper(FreePool.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.FreePool
    .createOrWaitForConnection(FreePool.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.PoolManager
    .reserve(PoolManager.java(Compiled Code))

    at com.ibm.ejs.j2c.ConnectionManager
    .allocateMCWrapper(ConnectionManager.java(Compiled Code))

    at com.ibm.ejs.j2c.ConnectionManager
    .allocateConnection(ConnectionManager.java(Compiled Code))

    at com.siebel.integration.jca.cci.SiebelConnectionFactory.getConnection(Unknown Source)

    at com.siebel.integration.adapter.SiebelJCAAdapterBase
    .invoke(SiebelJCAAdapterBase.java(Compiled Code))

    ...

    [SIEBEL INFO] Thread[Servlet.Engine.Transports : 2,5,main] [2010-11-05 07:53:26.243] [SiebelConnection(507473761)] Opened a new connection to Siebel (Siebel session : siebel.tcpip.none.none://myserver.mycompany.com:2321/esblp01/SCCObjMgr_enu/!10.6373.3ba70.465c2246)

    [SIEBEL INFO] Thread[Thread-56,5,main] [2010-11-05 07:54:38.484] [SiebelConnection(974516018)] Closing the connection

    java.lang.Throwable

    at com.siebel.integration.util.a.trace(Unknown Source)

    at com.siebel.integration.util.SiebelTrace.trace(Unknown Source)

    at com.siebel.integration.jca.cci.SiebelConnection.a(Unknown Source)

    at com.siebel.integration.jca.cci.SiebelConnection.close(Unknown Source)

    at com.siebel.integration.jca.spi.SiebelManagedConnection.destroy(Unknown Source)

    at com.ibm.ejs.j2c.MCWrapper.destroy(MCWrapper.java:1380)

    at com.ibm.ejs.j2c.poolmanager.FreePool
    .cleanupAndDestroyMCWrapper(FreePool.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.PoolManager
    .reclaimConnections(PoolManager.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.PoolManager
    .executeTask(PoolManager.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.TaskTimer
    .executeTask(TaskTimer.java(Compiled Code))

    at com.ibm.ejs.j2c.poolmanager.TaskTimer.run(TaskTimer.java:113)

  • Logging execution of a request in LOG_INFO (level 3).

    Previously, execution of a request was logged in LOG_DEBUG. Now the request is logged in LOG_INFO with no call stack, for example:

    [SIEBEL INFO] Thread[Servlet.Engine.Transports : 2,5,main] [2010-11-05 07:53:26.244] [SiebelConnection(507473761)] Executing com.siebel.integration.jca.client.SiebelInteractionSpec@1b6bef7c

Mapping a JCA Thread to a Siebel Server Task and Log File

From the JCA logging information, you can find the Siebel Server task and log file, which can be useful in diagnosing threads that use large amounts of CPU time.

To map a JCA thread to a Siebel Server task and log file

  1. Examine the JCA log file to find the high-CPU thread, for example:

    [SIEBEL INFO] Thread[Servlet.Engine.Transports : 2,5,main] [2010-11-05 07:53:26.243] [SiebelConnection(507473761)] Opened a new connection to Siebel (Siebel session : siebel.tcpip.none.none://myserver.mycompany.com:2321/esblp01/SCCObjMgr_enu/!10.6373.3ba70.465c2246)

    The Siebel session URL takes the following form:

    siebel[.transport][.encryption][.compression]://host[:port]/EnterpriseServer/AppObjMgr_lang/!AppObjMgrID.ProcessID.TaskID.timestamp

    where the Application Object Manager ID, process ID, task ID, and timestamp are represented by hexadecimal numbers

  2. Use the Siebel session URL to find the following parameters, converting hexadecimal numbers to decimal:
    Parameter
    Example

    Host

    myserver.mycompany.com

    Siebel Enterprise Server

    esblp01

    Application Object Manager_lang

    SCCObjMgr_enu

    Application Object Manager ID

    10 (16 decimal)

    Task ID

    3ba70 (244336 decimal)
  3. Find the corresponding Siebel Server log file, which is in the SIEBEL_SERVER_ROOT/log directory:
    • Windows:

    AppObjMgr_lang_AppObjMgrID_taskID.log

    For example:

    SCCObjMgr_enu_0016_244336.log

    • UNIX:

    AppObjMgr_lang_taskID.log

    For example:

    SCCObjMgr_enu_244336.log

    
Transports and Interfaces: Siebel Enterprise Application Integration Copyright © 2011, Oracle and/or its affiliates. All rights reserved. Legal Notices.