Using pooling logging

Enabling pooling logging in addition to client‑side logging can be beneficial for any application that uses Java connection pooling. Errors specific to the pool, such as exceptions thrown by the pooling support methods or a time‑out while waiting for a connection, are recorded only in the pooling log file—not in the client‑side log files. Depending on the logging level requested, in addition to errors the pooling log file may also contain actions relating to the creation and maintenance of the pool, such as the minpool and maxpool settings, time‑out values, registered pooling support methods, and inPool and inUse counts.

Pooling logging is specified in the pooling properties file with the poolLogFile and poolLogLevel settings. All pools use a single log file. If the file does not exist, it will be created; if it already exists, additional material is appended to the end. In pooling logging, output can be written only to a file, so a log filename is required.

Two levels of pooling logging are available: full and error‑only. Full includes informational messages, such as those generated when the pool is started, in addition to errors and exceptions. When running an application that uses pooling in a production environment, we recommend that you enable error‑only pooling logging in conjunction with error‑only client‑side logging. Full logging may be useful during development, but we do not recommend it for production. If a pool log file is specified, but no logging level is specified, error level logging will take place.

To enable pooling logging

All settings are in the pooling properties file.

See Specifying pool logging options for additional information on setting logging options in the pooling properties file.

Sample log files

This sample shows the pool creation and maintenance information that is logged when poolLogLevel is set to “all”. If errors occur, they will be logged also.

Mon Nov 18 06:43:19 PST 2013: MyPool: ************************
Mon Nov 18 06:43:19 PST 2013: MyPool: pool  =  MyPool
Mon Nov 18 06:43:19 PST 2013: MyPool: minPool  =  3
Mon Nov 18 06:43:19 PST 2013: MyPool: maxPool  =  6
Mon Nov 18 06:43:19 PST 2013: MyPool: poolReturn  =  true
Mon Nov 18 06:43:19 PST 2013: MyPool: propertiesFile  =  c:\wrk\myProps.ini
Mon Nov 18 06:43:19 PST 2013: MyP ool: connectWaitTimeout  =  10
Mon Nov 18 06:43:19 PST 2013: MyPool: poolMethodTimeout  =  10
Mon Nov 18 06:43:19 PST 2013: MyPool: initializationMethodID  =  Pool3_Init
Mon Nov 18 06:43:19 PST 2013: MyPool: activationMethodID  =  Pool3activate
Mon Nov 18 06:43:19 PST 2013: MyPool: deactivationMethodID  =  Pool3_deactivate
Mon Nov 18 06:43:19 PST 2013: MyPool: cleanupMethodID  =  Pool3_cleanup
Mon Nov 18 06:43:19 PST 2013: MyPool: poolableMethodID  =  null
Mon Nov 18 06:43:19 PST 2013: MyPool: ************************
Mon Nov 18 06:43:19 PST 2013: MyPool: Initialized pool 
Mon Nov 18 06:43:19 PST 2013: MyPool: Created a new connection in pool 
Mon Nov 18 06:43:19 PST 2013: MyPool: Initialize method  =  Pool3_Init
Mon Nov 18 06:43:19 PST 2013: MyPool: Register Cleanup method  =  Pool3_cleanup
Mon Nov 18 06:43:19 PST 2013: MyPool: Created a new connection in pool 
Mon Nov 18 06:43:19 PST 2013: MyPool: Initialize method  =  Pool3_Init
Mon Nov 18 06:43:19 PST 2013: MyPool: Register Cleanup method  =  Pool3_cleanup
Mon Nov 18 06:43:19 PST 2013: MyPool: After Initialized pool 
Mon Nov 18 06:43:19 PST 2013: MyPool: activate method  =  Pool3_activate
Mon Nov 18 06:43:19 PST 2013: MyPool: SWPPool getConnection 1 Total pool count  =  2 inPool  =  1 inUse  =  1
Mon Nov 18 06:43:19 PST 2013: MyPool: activate method  =  Pool3_activate
Mon Nov 18 06:43:20 PST 2013: MyPool: SWPPool getConnection 2 Total pool count  =  2 inPool  =  0 inUse  =  2

The sample below shows information logged when error‑only logging is enabled. In this case, the pool is at maximum size and in a loop waiting for a free connection; before one becomes available, a time‑out exception occurs because an initialization method takes too long to return.

Mon Nov 18 07:06:59 PST 2013: MyPool: Attempted to get connection from 
pool while at maximum.  Total pool count  =  6 inPool  =  0 inUse  =  6
Mon Nov 18 07:07:00 PST 2013: MyPool: Attempted to get connection from 
pool while at maximum.  Total pool count  =  6 inPool  =  0 inUse  =  6
.
.
.
Mon Nov 18 07:15:51 PST 2013: MyPool: Initialization method failed 
java.io.InterruptedIOException: Timeout waiting for xcall to return ‑ 
Read timed out
   at Synergex.net.LauncherSession.request(LauncherSession.java:949)
   at Synergex.synProxy.SynergyWebProxy.SendMsgToSynergy(SynergyWebProxy.java:1217)
   at Synergex.synProxy.SynergyWebProxy.makeCall(SynergyWebProxy.java:1156)
   at Synergex.synProxy.SynergyWebProxy.xcall(SynergyWebProxy.java:1520)
   at Synergex.util.SWPManager$SWPPool.newConnection(SWPManager.java:1220)
   at Synergex.util.SWPManager$SWPPool.FreeConnectionAdd(SWPManager.java:1298)
   at Synergex.util.SWPManager$SWPPool.addToMinimum(SWPManager.java:796)
   at Synergex.util.SWPManager$SWPPool.<init>(SWPManager.java:749)
   at Synergex.util.SWPManager.createPools(SWPManager.java:548)
   at Synergex.util.SWPManager.init(SWPManager.java:629)
   at Synergex.util.SWPManager.<init>(SWPManager.java:102)
   at Synergex.util.SWPManager.getInstance(SWPManager.java:66)
   at poolMsc.runtestTimeoutError(poolMsc.java:1209)
   at poolMsc.main(poolMsc.java:48)