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

Friday, June 6, 2014

Exception in thread "Thread-1" java.lang.ExceptionInInitializerError


We are using the Weblogic 12.1.1with Oracle Agile 9.3.3. After applying the hot fix, when we try to start the application we received the below error message

Please upgrade your admin data schema to 9.3.385.2
Shutting down the server...

<May 30, 2014 1:15:23 PM PDT> <Alert> <WebLogicServer> <BEA-000396> <Server shutdown has been requested by <WLS Kernel>.>
Exception in thread "Thread-1" java.lang.ExceptionInInitializerError  at weblogic.wsee.runtime.JMSStoreRoutableIDMapper.shutdown(JMSStoreRoutableIDMapper.java:479)
at weblogic.wsee.runtime.WebServicesRuntime.shutdown(WebServicesRuntime.java:236)
at weblogic.wsee.runtime.WseeService.haltService(WseeService.java:65)
at weblogic.server.ServiceActivator.halt(ServiceActivator.java:113)
at weblogic.t3.srvr.ServerServicesManager.haltInternal(ServerServicesManager.java:504)
at weblogic.t3.srvr.ServerServicesManager.halt(ServerServicesManager.java:336)
at weblogic.t3.srvr.T3Srvr.shutdown(T3Srvr.java:1122)
at weblogic.t3.srvr.T3Srvr.forceShutdown(T3Srvr.java:1026)
at weblogic.t3.srvr.T3Srvr$2.run(T3Srvr.java:1039)
Caused by: java.lang.IllegalStateException: Shutdown in progress
at java.lang.ApplicationShutdownHooks.add(ApplicationShutdownHooks.java:66)
at java.lang.Runtime.addShutdownHook(Runtime.java:211)
at weblogic.wsee.persistence.LogicalStore.<clinit>(LogicalStore.java:159)


From the error it is clear that the admin data schema needs to be upgrade. That means the hot fix have Database component and that needs to run after the hot fix.

I found a Database script i.e. oracle_933HF30.sql and applied to upgrade the admin data schema.

Now the application comes online without any issues.

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