Document Indexing fail

[dario]

My document indexing task is having trouble. Once it starts indexing, the progress bar stays at 0% for a while. If I right-click "Stop", it doesn't stop. Than if I right click again, all the options are grayed out. Than when I look at the logs I get this:

2011-04-24 23:02:26.484 INFO com.logicaldoc.core.searchengine.IndexerTask Found a total of 500 documents to be indexed
2011-04-25 08:43:12.444 ERROR com.logicaldoc.core.searchengine.IndexerTask Could not roll back Hibernate transaction; nested exception is org.hibernate.TransactionException: JDBC rollback failed


org.springframework.transaction.TransactionSystemException: Could not roll back Hibernate transaction; nested exception is org.hibernate.TransactionException: JDBC rollback failed
at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:679)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.doRollbackOnCommitException(AbstractPlatformTransactionManager.java:895)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:782)
at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723)
at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy25.reindex(Unknown Source)
at com.logicaldoc.core.searchengine.IndexerTask.runTask(IndexerTask.java:84)
at com.logicaldoc.core.task.Task.run(Task.java:144)
at sun.reflect.GeneratedMethodAccessor67.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.util.MethodInvoker.invoke(MethodInvoker.java:273)
at org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean$MethodInvokingJob.executeInternal(MethodInvokingJobDetailFactoryBean.java:264)
at org.springframework.scheduling.quartz.QuartzJobBean.execute(QuartzJobBean.java:86)
at org.quartz.core.JobRunShell.run(JobRunShell.java:216)
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549)
Caused by: org.hibernate.TransactionException: JDBC rollback failed
at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:204)
at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:676)
... 18 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.Connection was implicitly closed by the driver.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
at com.mysql.jdbc.Util.getInstance(Util.java:384)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:984)
at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:929)
at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1193)
at com.mysql.jdbc.ConnectionImpl.getMutex(ConnectionImpl.java:3035)
at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:4644)
at org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:368)
at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.rollback(PoolingDataSource.java:323)
at org.hibernate.transaction.JDBCTransaction.rollbackAndResetAutoCommit(JDBCTransaction.java:217)
at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:196)
... 19 more
Caused by: com.mysql.jdbc.exceptions.jdbc4.CommunicationsException: The last packet successfully received from the server was 34,845,711 milliseconds ago. The last packet sent successfully to the server was 34,845,711 milliseconds ago. is longer than the server configured value of 'wait_timeout'. You should consider either expiring and/or testing connection validity before use in your application, increasing the server configured values for client timeouts, or using the Connector/J connection property 'autoReconnect=true' to avoid this problem.
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(Unknown Source)
at java.lang.reflect.Constructor.newInstance(Unknown Source)
at com.mysql.jdbc.Util.handleNewInstance(Util.java:409)
at com.mysql.jdbc.SQLError.createCommunicationsException(SQLError.java:1118)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3321)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1940)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2113)
at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2568)
at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2113)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:2275)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:96)
at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:208)
at org.hibernate.loader.Loader.getResultSet(Loader.java:1812)
at org.hibernate.loader.Loader.doQuery(Loader.java:697)
at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
at org.hibernate.loader.Loader.doList(Loader.java:2232)
at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2129)
at org.hibernate.loader.Loader.list(Loader.java:2124)
at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:363)
at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1149)
at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
at org.springframework.orm.hibernate3.HibernateTemplate$30.doInHibernate(HibernateTemplate.java:921)
at org.springframework.orm.hibernate3.HibernateTemplate$30.doInHibernate(HibernateTemplate.java:1)
at org.springframework.orm.hibernate3.HibernateTemplate.doExecute(HibernateTemplate.java:406)
at org.springframework.orm.hibernate3.HibernateTemplate.executeWithNativeSession(HibernateTemplate.java:374)
at org.springframework.orm.hibernate3.HibernateTemplate.find(HibernateTemplate.java:912)
at com.logicaldoc.core.HibernatePersistentObjectDAO.findIdsByWhere(HibernatePersistentObjectDAO.java:110)
at com.logicaldoc.core.HibernatePersistentObjectDAO.findIdsByWhere(HibernatePersistentObjectDAO.java:97)
at com.logicaldoc.core.document.dao.HibernateDocumentDAO.findShortcutIds(HibernateDocumentDAO.java:687)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy14.findShortcutIds(Unknown Source)
at com.logicaldoc.core.document.DocumentManagerImpl.reindex(DocumentManagerImpl.java:299)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.lang.reflect.Method.invoke(Unknown Source)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:309)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:110)
... 13 more
Caused by: java.net.SocketException: Software caused connection abort: socket write error
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(Unknown Source)
at java.net.SocketOutputStream.write(Unknown Source)
at java.io.BufferedOutputStream.flushBuffer(Unknown Source)
at java.io.BufferedOutputStream.flush(Unknown Source)
at com.mysql.jdbc.MysqlIO.send(MysqlIO.java:3302)
... 60 more




Any ideas why its having trouble with this (mysql?)

[agaspa]

Your MySQL schema seems to be MyISAM.
You must ensure that your mysql is able to rollback transactions and that the db schema of logicaldoc is created as InnoDB

[dario]

We used the LogicalDOC install to setup our database and everything that came with it. It did it all automatically. It was put on a Windows Server 2008 machine, so it should work. It was also previously installed on another machine with server 08 on it, and it was still having trouble with the indexing.

[agaspa]

Hi dario,
so you installed using the mysql provided with the installer, is this correct ?

Anyway please tell me a thing, are you installing on a Virtual Machine ?
How much memory has been allocated to this virtual machine?
It can be a problem of assigned resources: CPU or memory

Regarding the Stop issue of the indexer task you have to know that the stopping is not synchronous, you have to wait that the task completes at least the step currently started (indexing of the currently processed document)

I suggest you report the problem on the issue tracker attaching the extract of your log
http://issues.logicaldoc.com

[dario]

No, its not installed on a virtual machine. The machine its running on has Quad core cpu and about 12GB RAM. Thanks for the tip on the Stop issue.