INFO | jvm 1 | 2022/04/27 19:51:15 | 4 | Apr 27, 2022 7:51:14 PM com.ca.wcc.dbresource.datasource.UnlockingDatasource setParameters
INFO | jvm 1 | 2022/04/27 19:51:15 | 4 | INFO: URL= jdbc:oracle:thin:@AUTOSYS_WCC, Driver= oracle.jdbc.driver.OracleDriver
INFO | jvm 1 | 2022/04/27 19:51:15 | 4 | Apr 27, 2022 7:51:14 PM com.ca.wcc.dbresource.datasource.WccDataSource registerMBean
INFO | jvm 1 | 2022/04/27 19:51:15 | 4 | INFO: Trying to create connection pool, retry attempt - 1
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | Apr 27, 2022 7:51:17 PM org.apache.tomcat.jdbc.pool.ConnectionPool init
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | SEVERE: Unable to create initial connections of pool.
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | java.sql.SQLRecoverableException: IO Error: The Network Adapter could not establish the connection
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:774)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:688)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:39)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:691)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:347)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:228)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.ConnectionPool.createConnection(ConnectionPool.java:769)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:697)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.ConnectionPool.init(ConnectionPool.java:496)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.ConnectionPool.<init>(ConnectionPool.java:154)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.DataSourceProxy.pCreatePool(DataSourceProxy.java:121)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.tomcat.jdbc.pool.DataSourceProxy.createPool(DataSourceProxy.java:110)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at com.ca.wcc.dbresource.datasource.WccDataSource.registerMBean(Unknown Source)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at com.ca.wcc.dbresource.datasource.UnlockingDatasource.setParameters(Unknown Source)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at com.ca.wcc.dbresource.datasource.WccDataSource.setPrefix(Unknown Source)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at java.lang.reflect.Method.invoke(Method.java:498)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.factory.BeanFactory.getObjectInstance(BeanFactory.java:264)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.factory.FactoryBase.getObjectInstance(FactoryBase.java:96)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at javax.naming.spi.NamingManager.getObjectInstance(NamingManager.java:332)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.NamingContext.lookup(NamingContext.java:864)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.NamingContext.lookup(NamingContext.java:158)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.NamingContextBindingsEnumeration.nextElementInternal(NamingContextBindingsEnumeration.java:115)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.NamingContextBindingsEnumeration.next(NamingContextBindingsEnumeration.java:69)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.naming.NamingContextBindingsEnumeration.next(NamingContextBindingsEnumeration.java:32)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.mbeans.GlobalResourcesLifecycleListener.createMBeans(GlobalResourcesLifecycleListener.java:133)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.mbeans.GlobalResourcesLifecycleListener.createMBeans(GlobalResourcesLifecycleListener.java:140)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.mbeans.GlobalResourcesLifecycleListener.createMBeans(GlobalResourcesLifecycleListener.java:107)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.mbeans.GlobalResourcesLifecycleListener.lifecycleEvent(GlobalResourcesLifecycleListener.java:82)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:920)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.startup.Catalina.start(Catalina.java:772)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at java.lang.reflect.Method.invoke(Method.java:498)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at java.lang.reflect.Method.invoke(Method.java:498)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at org.tanukisoftware.wrapper.WrapperStartStopApp.run(WrapperStartStopApp.java:429)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at java.lang.Thread.run(Thread.java:827)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | Caused by: oracle.net.ns.NetException: The Network Adapter could not establish the connection
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:523)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.resolver.AddrResolution.resolveAndExecute(AddrResolution.java:521)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:660)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.ns.NSProtocol.establishConnection(NSProtocol.java:639)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.ns.NSProtocolNIO.negotiateConnection(NSProtocolNIO.java:189)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.ns.NSProtocol.connect(NSProtocol.java:317)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1438)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:518)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | ... 48 more
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | Caused by: java.io.IOException: Socket read timed out, socket connect lapse 4 ms. /10.10.11.12 1521 3 1 true
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:209)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.ConnOption.connect(ConnOption.java:161)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.ConnStrategy.execute(ConnStrategy.java:470)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | ... 55 more
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | Caused by: java.io.InterruptedIOException: Socket read timed out
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.TimeoutSocketChannel.handleInterrupt(TimeoutSocketChannel.java:307)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.TimeoutSocketChannel.<init>(TimeoutSocketChannel.java:84)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | at oracle.net.nt.TcpNTAdapter.connect(TcpNTAdapter.java:169)
INFO | jvm 1 | 2022/04/27 19:51:17 | 6 | ... 57 more
Customer's database was a load balanced configuration. Somehow the TRANSPORT_CONNECT_TIMEOUT of 3 seconds was not enough
AUTOSYS_WCC =
(DESCRIPTION = (CONNECT_TIMEOUT=90)(RETRY_COUNT=20)(RETRY_DELAY=3)(TRANSPORT_CONNECT_TIMEOUT=3)
(ADDRESS_LIST =
(LOAD_BALANCE = ON)
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode1.company.com)(PORT = 1521))
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode2.company.com)(PORT = 1521))
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode3.company.com)(PORT = 1521))
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode4.company.com)(PORT = 1521))
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode5.company.com)(PORT = 1521))
(ADDRESS = (PROTOCOL = TCP)(HOST = dbnode6.company.com)(PORT = 1521))
)
(CONNECT_DATA =
(SERVER = dedicated)
(SERVICE_NAME = AUTOSYS_WCC)
)
)
We did a tnsping AUTOSYS_WCC repeatedly. On some occasions it showed as taking >3 seconds
Release : 12.0
Component :
Increased the TRANSPORT_CONNECT_TIMEOUT=30 and restarted WCC. It connected to the database fine and started working normally