6.7 Server log errors that hose the rhythmyx server patch RX16504

Sharyn_Lyons · June 29, 2011, 1:26pm

When we start getting these error messages in the server.log Rhythmyx slows down to a halt and is unusuable. We have to reboot the server in order to recover and sometimes that doesn’t work either. This seems to happen after a certain period of time has passed from days to weeks. Has anyone seen these errors before? FYI we already have a ticket open with Percussion TS just wanted to see if anyone else has experienced this.



2011-06-23 11:10:19,445 WARN  [org.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: HY010
2011-06-23 11:10:19,445 ERROR [org.hibernate.util.JDBCExceptionReporter] Invalid state, the Connection object is closed.
2011-06-23 11:10:19,445 ERROR [org.hibernate.transaction.JDBCTransaction] JDBC rollback failed
java.sql.SQLException: Invalid state, the Connection object is closed.


2011-06-23 09:44:50,117 ERROR [org.jboss.invocation.pooled.server.ServerThread] Failed to initialize
java.io.StreamCorruptedException: invalid stream header: 05000B03
 at java.io.ObjectInputStream.readStreamHeader(Unknown Source)
 at java.io.ObjectInputStream.<init>(Unknown Source)
 at org.jboss.invocation.pooled.interfaces.OptimizedObjectInputStream.<init>(OptimizedObjectInputStream.java:121)
 at org.jboss.invocation.pooled.server.ServerThread.dorun(ServerThread.java:245)
 at org.jboss.invocation.pooled.server.ServerThread.run(ServerThread.java:139)
2011-06-23 09:44:50,133 ERROR [org.jboss.invocation.pooled.server.ServerThread] Failed to initialize
java.io.StreamCorruptedException: invalid stream header: 05000B03
 at java.io.ObjectInputStream.readStreamHeader(Unknown Source)
 at java.io.ObjectInputStream.<init>(Unknown Source)
 at org.jboss.invocation.pooled.interfaces.OptimizedObjectInputStream.<init>(OptimizedObjectInputStream.java:121)
 at org.jboss.invocation.pooled.server.ServerThread.dorun(ServerThread.java:245)
 at org.jboss.invocation.pooled.server.ServerThread.run(ServerThread.java:139)
2011-06-23 09:44:50,148 ERROR [org.jboss.invocation.pooled.server.ServerThread] Failed to initialize
java.io.StreamCorruptedException: invalid stream header: 05000B03
 at java.io.ObjectInputStream.readStreamHeader(Unknown Source)
 at java.io.ObjectInputStream.<init>(Unknown Source)
 at org.jboss.invocation.pooled.interfaces.OptimizedObjectInputStream.<init>(OptimizedObjectInputStream.java:121)
 at org.jboss.invocation.pooled.server.ServerThread.dorun(ServerThread.java:245)
 at org.jboss.invocation.pooled.server.ServerThread.run(ServerThread.java:139)


]2011-06-15 13:59:20,490 ERROR [org.hibernate.transaction.JDBCTransaction] JDBC commit failed
java.sql.SQLException: I/O Error: Connection reset
 at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1052)
 at net.sourceforge.jtds.jdbc.TdsCore.submitSQL(TdsCore.java:898)
 at net.sourceforge.jtds.jdbc.ConnectionJDBC2.setAutoCommit(ConnectionJDBC2.java:2175)
 at org.jboss.resource.adapter.jdbc.BaseWrapperManagedConnection.checkTransaction(BaseWrapperManagedConnection.java:362)
 at org.jboss.resource.adapter.jdbc.WrappedConnection.checkTransaction(WrappedConnection.java:514)
 at org.jboss.resource.adapter.jdbc.WrappedConnection.commit(WrappedConnection.java:330)
 at org.hibernate.transaction.JDBCTransaction.commitAndResetAutoCommit(JDBCTransaction.java:139)
 at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:115)
 at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
 at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
 at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
 at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
 at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
 at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
 at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
 at $Proxy130.createId(Unknown Source)
 at com.percussion.data.PSIdGenerator.getNextId(Unknown Source)
 at com.percussion.log.l.o00000(Unknown Source)
 at com.percussion.log.l.o00000(Unknown Source)
 at com.percussion.log.b.o00000(Unknown Source)
 at com.percussion.log.o.Object(Unknown Source)
 at com.percussion.log.o.run(Unknown Source)
Caused by: java.net.SocketException: Connection reset
 at java.net.SocketInputStream.read(Unknown Source)
 at java.io.DataInputStream.readFully(Unknown Source)
 at java.io.DataInputStream.readFully(Unknown Source)
 at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:841)
 at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:722)
 at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
 at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
 at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
 at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3928)
 at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1045)
 ... 21 more
2011-06-15 13:59:20,490 ERROR [com.percussion.data.ub] Application sys_ageSupport, Dataset agecontentlist, Request agecontentlist
Parameters: 
had the following problem: I/O Error: Connection reset
java.sql.SQLException: I/O Error: Connection reset
 at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1052)
 at net.sourceforge.jtds.jdbc.TdsCore.microsoftPrepare(TdsCore.java:1178)
 at net.sourceforge.jtds.jdbc.ConnectionJDBC2.prepareSQL(ConnectionJDBC2.java:657)
 at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.executeQuery(JtdsPreparedStatement.java:776)
 at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:211)
 at com.percussion.data.bb.super(Unknown Source)
 at com.percussion.data.dd.Ô00000(Unknown Source)
 at com.percussion.data.dd.makeInternalRequest(Unknown Source)
 at com.percussion.server.agent.PSAging.getDocument(Unknown Source)
 at com.percussion.server.agent.PSAging.run(Unknown Source)
 at java.util.TimerThread.mainLoop(Unknown Source)
 at java.util.TimerThread.run(Unknown Source)
Caused by: java.net.SocketException: Connection reset
 at java.net.SocketInputStream.read(Unknown Source)
 at java.io.DataInputStream.readFully(Unknown Source)
 at java.io.DataInputStream.readFully(Unknown Source)
 at net.sourceforge.jtds.jdbc.SharedSocket.readPacket(SharedSocket.java:841)
 at net.sourceforge.jtds.jdbc.SharedSocket.getNetPacket(SharedSocket.java:722)
 at net.sourceforge.jtds.jdbc.ResponseStream.getPacket(ResponseStream.java:466)
 at net.sourceforge.jtds.jdbc.ResponseStream.read(ResponseStream.java:103)
 at net.sourceforge.jtds.jdbc.ResponseStream.peek(ResponseStream.java:88)
 at net.sourceforge.jtds.jdbc.TdsCore.wait(TdsCore.java:3928)
 at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1045)
 ... 11 more
2011-06-15 13:59:20,506 INFO  [STDOUT] Exception in thread "Thread-9" 
2011-06-15 13:59:20,506 INFO  [com.percussion.server.PSServerLogHandler] appid: 0 type: 1 time: Wed Jun 15 13:59:20 EDT 2011 msg: An internal error (end-condition) was encountered. An unexpected exception occurred:
An unexpected exception occurred. The reason was: An exception occurred while processing the internal request handler call: [1] 08S01: I/O Error: Connection reset . Please consult the log for further information..
The call-stack was:
com.percussion.server.agent.PSAgentException: An exception occurred while processing the internal request handler call: [1] 08S01: I/O Error: Connection reset 
 at com.percussion.server.agent.PSAging.getDocument(Unknown Source)
 at com.percussion.server.agent.PSAging.run(Unknown Source)
 at java.util.TimerThread.mainLoop(Unknown Source)
 at java.util.TimerThread.run(Unknown Source)
 
2011-06-15 13:59:20,506 ERROR [com.percussion.AgentMgr] An unexpected exception occurred. The reason was: An exception occurred while processing the internal request handler call: [1] 08S01: I/O Error: Connection reset . Please consult the log for further information.
2011-06-15 13:59:20,584 INFO  [STDOUT] org.springframework.transaction.TransactionSystemException: Could not commit Hibernate transaction; nested exception is org.hibernate.TransactionException: JDBC commit failed
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:659)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:709)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:678)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at $Proxy130.createId(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.data.PSIdGenerator.getNextId(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.log.l.o00000(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.log.l.o00000(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.log.b.o00000(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.log.o.Object(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at com.percussion.log.o.run(Unknown Source)
2011-06-15 13:59:20,647 INFO  [STDOUT] Caused by: org.hibernate.TransactionException: JDBC commit failed
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:130)
2011-06-15 13:59:20,647 INFO  [STDOUT]  at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:655)
2011-06-15 13:59:20,647 INFO  [STDOUT]  ... 13 more
2011-06-15 13:59:20,647 INFO  [STDOUT] Caused by: java.sql.SQLException: I/O Error: Connection reset
2011-06-15 13:59:20,647 INFO  [STDOUT]  at net.sourceforge.jtds.jdbc.TdsCore.executeSQL(TdsCore.java:1052)
2011-06-15 13:59:20,662 INFO  [STDOUT]  at net.sourceforge.jtds.jdbc.TdsCore.submitSQL(TdsCore.java:898)
2011-06-15 13:59:20,662 INFO  [STDOUT]  at

darrell.wells · July 6, 2011, 7:28am

What RDBMS and version? What OS is the app server running on? Does the database exist on the same physical machine as the Rhythmyx app server?

2011-06-15 13:59:20,490 ERROR [org.hibernate.transaction.JDBCTransaction] JDBC commit failed
java.sql.SQLException: I/O Error: Connection reset

The app server keeps several database connections open. If they have all failed, then that indicates to me that the app server can no longer reach the database server. When you encounter this issue again (since it sounds frequent but not definitively reproducible), see if you can connect to the database in some other way like with a simple Perl script at the command line. That will narrow down whether it’s the Rhythmyx application or the app server / db network connectivity.

To answer your specific question, I’ve only seen this error once, and that was when a database server crashed and took more than 5 minutes to reboot.

igorh · August 18, 2011, 4:04pm

We are seeing this as well (v6.7). Did you have any progress with your ticket with Tech Support?

Richard_King · August 24, 2011, 11:31am

Hi

Has anyone got an answer on this as yet please?

I have experienced the same problem several times whilst test publishing our 6.7 upgrade. The error appears on an edition with 24 content lists and approximately 16,000 items. I did a test, splitting these into two separate editions, and don’t get the same problem.

Thanks and best wishes

Richard

Nate_Chadwick · August 25, 2011, 7:50am

Which version of Windows and SQL Server are you all running? I wonder if there is something common in the environments that is causing the issue.

-nate

Richard_King · August 25, 2011, 8:40am

Hi Nate

Thanks for the response.

We are on Windows Server 2003 SE SP2 and using SQL2008.

Regards

Richard

Nate_Chadwick · August 25, 2011, 10:06am

Sharon/Igorh are you running on the same versions? What is the service pack level on the SQL Server? Just trying to sort out if this is a version specific thing.

Also Richard it is definitely worth taking the server down, cleaning out the \AppServer\server\rx mp, work, and data directories, applying the latest patch and restarting. Verify there are no network issues in server event logs on the database server and the windows server running Rhythmyx.