Tuesday, June 24, 2014

java.sql.SQLRecoverableException: IO Error: Connection reset


I have come across below error during Oracle Agile Managed Server deployment (Agile 9.3.3). When trying to startup the Managed server which is using Weblogic12c, it didn’t startup and found below error in logfile.

Your environment has been set.
AgileAuthenticationProviderImpl.initialize
log4j:WARN No appenders could be found for logger (com.agile.util.sql.OracleConnectionImpl).
log4j:WARN Please initialize the log4j system properly.
java.sql.SQLRecoverableException: IO Error: Connection reset
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:467)
at oracle.jdbc.driver.PhysicalConnection.<init>(PhysicalConnection.java:546)
at oracle.jdbc.driver.T4CConnection.<init>(T4CConnection.java:236)
at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:521)
at oracle.jdbc.pool.OracleDataSource.getPhysicalConnection(OracleDataSource.java:280)
at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:207) at
oracle.jdbc.pool.OracleConnectionPoolDataSource.getPhysicalConnection(OracleConnectionPool Data Source.java:139) at oracle.jdbc.pool.OracleConnectionPoolDataSource.getPooledConnection (Oracle ConnectionPool Data Source.java:88) at........ com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper.java:110)
at java.security.AccessController.doPrivileged(Native Method) at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper.java:106)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at javax.security.auth.login.LoginContext.invoke(LoginContext.java:762)
at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:690)
at javax.security.auth.login.LoginContext$4.run(LoginContext.java:688)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:687)
at javax.security.auth.login.LoginContext.login(LoginContext.java:595) at com.bea.common.security.internal.service.JAASLoginServiceImpl.login(JAASLoginServiceImpl.java:113)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606) at com.bea.common.security.internal.utils.Delegator$ProxyInvocationHandler.invoke(Delegator.java:57)
at com.sun.proxy.$Proxy13.login(Unknown Source) at weblogic.security.service.internal.WLSJAASLoginServiceImpl$ServiceImpl.login(WLSJAASLoginServiceImpl.java:89) at com.bea.common.security.internal.service.JAASAuthenticationServiceImpl.authenticate(JAASAuthenticationServiceImpl.java:82)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606) at com.bea.common.security.internal.utils.Delegator$ProxyInvocationHandler.invoke(Delegator.java:57)
at com.sun.proxy.$Proxy34.authenticate(Unknown Source) at weblogic.security.service.WLSJAASAuthenticationServiceWrapper.authenticate(WLSJAASAuthenticationServiceWrapper.java:40) at weblogic.security.service.PrincipalAuthenticator.authenticate(PrincipalAuthenticator.java:338) at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.doBootAuthorization(CommonSecurityServiceManagerDelegateImpl.
java:930) at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl. initialize(CommonSecurityServiceManagerDelegateImpl.java:1054) at
weblogic.security.service.SecurityServiceManager.initialize(SecurityServiceManager.java:873)
at weblogic.security.SecurityService.start(SecurityService.java:148)
at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:118)
at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
at oracle.net.ns.DataPacket.send(DataPacket.java:210)
at oracle.net.ns.NetOutputStream.flush(NetOutputStream.java:230)
at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:312)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:260)
at oracle.net.ns.NetInputStream.read(NetInputStream.java:185)
at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket (T4CSocketInputStreamWrapper. java:124) at oracle.jdbc.driver.T4CSocketInputStream Wrapper.read(T4CSocketInputStreamWrapper.java:80)
at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1137)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:290)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:192)
at oracle.jdbc.driver.T4CTTIoauthenticate.doOSESSKEY(T4CTTIoauthenticate.java:404)
at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:385)
... 59 more
java.sql.SQLRecoverableException: IO Error: Connection reset

You will also see below error in the log file, but these errors will mislead you

<Jun 19, 2014 2:13:44 PM PDT> <Critical> <Security> <BEA-090402> <Authentication denied: Boot identity not valid; The user name and/or password from the boot identity file (boot.properties) is not valid. The boot identity may have been changed since the boot identity file was created. Please edit and update the boot identity file with the proper values of username and password. The first time the updated boot identity file is used to start the server, these new values are encrypted.>

<Jun 19, 2014 2:13:44 PM PDT> <Critical> <WebLogicServer> <BEA-000386> <Server subsystem failed. Reason: weblogic.security.SecurityInitializationException: Authentication denied: Boot identity not valid; The user name and/or password from the boot identity file (boot.properties) is not valid. The boot identity may have been changed since the boot identity file was created. Please edit and update the boot identity file with the proper values of username and password. The first time the updated boot identity file is used to start the server, these new values are encrypted.
...(CommonSecurityServiceManagerDelegateImpl.java:960) at weblogic.security.service.CommonSecurityServiceManagerDelegateImpl.initialize(CommonSecurityServiceManagerDelegateImpl.java:1054) at weblogic.security.service.SecurityServiceManager.initialize(SecurityServiceManager.java:873)
at weblogic.security.SecurityService.start(SecurityService.java:148)
at weblogic.t3.srvr.SubsystemRequest.run(SubsystemRequest.java:64)
Truncated. see log file for complete stacktrace
Caused By: javax.security.auth.login.LoginException: java.lang.ExceptionInInitializerError
 at com.agile.admin.security.weblogic.WLSLoginModule.login
(WLSLoginModule.java:193) at com.bea.common.security.internal.service.LoginModuleWrapper$1.run(LoginModuleWrapper. java: 110 at java.security.AccessController.doPrivileged(Native Method)
at com.bea.common.security.internal.service.LoginModuleWrapper.login(LoginModuleWrapper .java:106) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)


Findings/troubleshooting

1. When trying to startup the Managed server the weblogic taking more time than expected

2. If you read the highlight error then you will understand what the exact cause for this error is “java.sql.SQLRecoverableException: IO Error: Connection reset”.

3. Found below warning in alert<sid>.log
WARNING: inbound connection timed out (ORA-3136)

4. The userid/password is correct

By looking the above findings it seems that weblogic taking more time and it was not able to connect to the database and timed out with ORA-3136 error. It looks like inbound connection timeout occurred.

Proposed Solution: I have changed the SQLNET.INBOUND_CONNECT_TIMEOUT from default (60 sec) value to 0(indefinite).

After changing the parameter the weblogic Instance comes online without any issues.

It looks like there is bug in Weblogic due to which it is not able to connect to database with in the specified time. Still troubleshooting to find the root cause, if I find anything will try to update in the post.

Regards,
Satishbabu Gunukula, Oracle ACE
http://www.oracleracexpert.com

5 comments:

  1. We have a similar issue occurring at our Clinic. We are vendored through Cerner, an outside company that provides us with the tools to manage our electronic medical record system. This is the error output from our server. Any ideas?
    Thu Oct 02 12:48:03 CDT 2014 INFO com.cerner.system.jdbc.metadriver.MetaDriverManager [com.cerner.system.cache.sensor.polling.PollingSensor-Coding.Extension-thread-1] - [Connection is eligible for retry for data source mhmk1 after a timeout of 2,000ms.]
    java.sql.SQLException: IO Error: Connection reset
    at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:467)
    at oracle.jdbc.driver.PhysicalConnection.(PhysicalConnection.java:546)
    at oracle.jdbc.driver.T4CConnection.(T4CConnection.java:236)
    at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32)
    at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:521)
    at oracle.jdbc.pool.OracleDataSource.getPhysicalConnection(OracleDataSource.java:280)
    at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:207)
    at oracle.jdbc.pool.OracleConnectionPoolDataSource.getPhysicalConnection(OracleConnectionPoolDataSource.java:139)
    at oracle.jdbc.pool.OracleConnectionPoolDataSource.getPooledConnection(OracleConnectionPoolDataSource.java:88)
    at oracle.jdbc.pool.OracleImplicitConnectionCache.makeCacheConnection(OracleImplicitConnectionCache.java:1598)
    at oracle.jdbc.pool.OracleImplicitConnectionCache.makeOneConnection(OracleImplicitConnectionCache.java:515)
    at oracle.jdbc.pool.OracleImplicitConnectionCache.getCacheConnection(OracleImplicitConnectionCache.java:475)
    at oracle.jdbc.pool.OracleImplicitConnectionCache.getConnection(OracleImplicitConnectionCache.java:357)
    at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:395)
    at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:179)
    at oracle.jdbc.pool.OracleDataSource.getConnection(OracleDataSource.java:157)
    at com.cerner.system.jdbc.metadriver.MetaDriverManager.createRawConnection(MetaDriverManager.java:409)
    at com.cerner.system.jdbc.metadriver.MetaDriverManager.createRaw(MetaDriverManager.java:288)
    at com.cerner.system.jdbc.ConnectionManager.getTransacted(ConnectionManager.java:91)
    at com.cerner.system.jdbc.ConnectionManager.getTransacted(ConnectionManager.java:127)
    at com.cerner.system.code.gladiator.cache.jdbc.BaseGladiatorJDBCInterrogator$TransactedActionImpl.interrogateByLogicalCnt(BaseGladiatorJDBCInterrogator.java:135)

    ReplyDelete
  2. Second part of log files:
    at com.cerner.system.code.gladiator.cache.jdbc.BaseGladiatorJDBCInterrogator$TransactedActionImpl.run(BaseGladiatorJDBCInterrogator.java:99)
    at com.cerner.system.code.gladiator.cache.jdbc.BaseGladiatorJDBCInterrogator$TransactedActionImpl.run(BaseGladiatorJDBCInterrogator.java:82)
    at com.cerner.system.transaction.TransactionManager.runInNewTransaction(TransactionManager.java:292)
    at com.cerner.system.transaction.TransactionManager.doTransactedRetry(TransactionManager.java:249)
    at com.cerner.system.transaction.TransactionManager.doTransactedRetry(TransactionManager.java:171)
    at com.cerner.system.cache.interrogator.jdbc.TransactedActionBaseInterrogator.discover(TransactedActionBaseInterrogator.java:206)
    at com.cerner.system.code.gladiator.cache.CodeSystemInterrogator.discover(CodeSystemInterrogator.java:84)
    at com.cerner.system.cache.sensor.polling.AbstractPollingSensor$InterrogatorProxy.discover(AbstractPollingSensor.java:934)
    at com.cerner.system.cache.sensor.polling.AbstractPollingSensor.poll(AbstractPollingSensor.java:497)
    at com.cerner.system.cache.sensor.polling.PollingSensor$Poller$PollerAction.run(PollingSensor.java:86)
    at com.cerner.system.cache.sensor.polling.PollingSensor$Poller$PollerAction.run(PollingSensor.java:84)
    at java.security.AccessController.doPrivileged(AccessController.java:224)
    at javax.security.auth.Subject.doAs(Subject.java:495)
    at com.cerner.system.cache.sensor.polling.PollingSensor$Poller.run(PollingSensor.java:74)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:453)
    at java.util.concurrent.FutureTask$Sync.innerRunAndReset(FutureTask.java:329)
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:162)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$101(ScheduledThreadPoolExecutor.java:110)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.runPeriodic(ScheduledThreadPoolExecutor.java:193)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:217)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:898)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:920)
    at java.lang.Thread.run(Thread.java:736)
    Caused by: java.net.SocketException: Connection reset
    at java.net.SocketInputStream.read(SocketInputStream.java:180)
    at oracle.net.ns.Packet.receive(Packet.java:300)
    at oracle.net.ns.NSProtocol.connect(NSProtocol.java:296)
    at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1102)
    at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:320)
    ... 43 more

    ReplyDelete
  3. make sure export /dev/urandom is being used rather than /dev/random. Good article here.

    ReplyDelete
  4. Java Training Institutes Java Training Institutes
    Java Spring Hibernate Training Institutes in Chennai J2EE Training Institutes in Chennai J2EE Training Institutes in Chennai Core Java Training Institutes in Chennai Core Java Training Institutes in Chennai

    Hibernate Online Training Hibernate Online Training Hibernate Training in Chennai Hibernate Training in Chennai Java Online Training Java Online Training Hibernate Training Institutes in ChennaiHibernate Training Institutes in Chennai

    ReplyDelete