About JCA Logging

The following are some of the characteristics of JCA logging:

  • Appending JCA logs to one file, which is found in the working directory of the JVM. 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. The call stack is a complete Java call stack.

  • Logging of thread names. All threads log to one file and 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)
    
  • Logging in LOG_DETAIL (level 4) is as follows:

    • 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
      
  • When a connection is opened or closed, the call stack is logged, as in the following 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.example.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). Requests are logged in LOG_INFO with no call stack, as in the following 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