AnsweredAssumed Answered

admin and other logins don't work - indexing issue

Question asked by aatamer on Jun 1, 2007
Latest reply on Jun 4, 2007 by derek
Today there were some problems with our Alfresco server.  Admin and other logins didn't work.  Our web-client properties had index.recovery.mode=FULL

We checked the logs and found the following error messages.

09:39:39,774 INFO  [node.index.FullIndexRecoveryComponent]    10 % complete.
[WARNING] Unknown Ptg 3d (61)
[WARNING] Unknown Ptg 3d (61)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
09:41:36,626 INFO  [node.index.FullIndexRecoveryComponent]    20 % complete.
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3d (61)
[WARNING] Unknown Ptg 3d (61)
09:45:21,417 INFO  [node.index.FullIndexRecoveryComponent]    30 % complete.
[WARNING] Unknown Ptg 3d (61)
[WARNING] Unknown Ptg 3d (61)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
[WARNING] Unknown Ptg 3c (60)
09:47:46,011 INFO  [node.index.FullIndexRecoveryComponent]    40 % complete.
09:50:43,601 INFO  [node.index.FullIndexRecoveryComponent]    50 % complete.
[WARNING] Unknown Ptg 3d (61)
09:53:46,683 INFO  [node.index.FullIndexRecoveryComponent]    60 % complete.
09:56:29,829 ERROR [orm.hibernate3.HibernateTransactionManager] Commit exception overridden by rollback exception
java.lang.IllegalStateException: Pool not open
   at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
   at org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916)
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:80)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:94)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
   at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:400)
   at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:287)
   at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:205)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:119)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:584)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:496)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:405)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:186)
   at org.alfresco.repo.transaction.TransactionUtil.executeInNonPropagatingUserTransaction(TransactionUtil.java:134)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexTransaction(FullIndexRecoveryComponent.java:283)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.performFullRecovery(FullIndexRecoveryComponent.java:206)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexImpl(FullIndexRecoveryComponent.java:165)
   at org.alfresco.repo.node.index.AbstractReindexComponent$1.doWork(AbstractReindexComponent.java:217)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:176)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
09:56:29,845 ERROR [orm.hibernate3.SessionFactoryUtils] Unexpected exception on closing Hibernate Session
java.lang.IllegalStateException: Pool not open
   at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
   at org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916)
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:80)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:94)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
   at org.hibernate.jdbc.ConnectionManager.cleanup(ConnectionManager.java:379)
   at org.hibernate.jdbc.ConnectionManager.close(ConnectionManager.java:318)
   at org.hibernate.impl.SessionImpl.close(SessionImpl.java:293)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.doClose(SessionFactoryUtils.java:787)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.closeSessionOrRegisterDeferredClose(SessionFactoryUtils.java:775)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.releaseSession(SessionFactoryUtils.java:748)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCleanupAfterCompletion(HibernateTransactionManager.java:662)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.cleanupAfterCompletion(AbstractPlatformTransactionManager.java:750)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:537)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:405)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:186)
   at org.alfresco.repo.transaction.TransactionUtil.executeInNonPropagatingUserTransaction(TransactionUtil.java:134)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexTransaction(FullIndexRecoveryComponent.java:283)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.performFullRecovery(FullIndexRecoveryComponent.java:206)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexImpl(FullIndexRecoveryComponent.java:165)
   at org.alfresco.repo.node.index.AbstractReindexComponent$1.doWork(AbstractReindexComponent.java:217)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:176)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
09:56:29,845 ERROR [util.transaction.SpringAwareUserTransaction] Transaction didn't commit
java.lang.IllegalStateException: Pool not open
   at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
   at org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916)
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:80)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:94)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
   at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:400)
   at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:287)
   at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:205)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:174)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:603)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.doRollbackOnCommitException(AbstractPlatformTransactionManager.java:629)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:524)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:469)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCommitTransactionAfterReturning(TransactionAspectSupport.java:266)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:405)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:186)
   at org.alfresco.repo.transaction.TransactionUtil.executeInNonPropagatingUserTransaction(TransactionUtil.java:134)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexTransaction(FullIndexRecoveryComponent.java:283)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.performFullRecovery(FullIndexRecoveryComponent.java:206)
   at org.alfresco.repo.node.index.FullIndexRecoveryComponent.reindexImpl(FullIndexRecoveryComponent.java:165)
   at org.alfresco.repo.node.index.AbstractReindexComponent$1.doWork(AbstractReindexComponent.java:217)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:176)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
09:56:29,845 ERROR [orm.hibernate3.SessionFactoryUtils] Unexpected exception on closing Hibernate Session
java.lang.IllegalStateException: Pool not open
   at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
   at org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916)
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:80)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:94)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
   at org.hibernate.jdbc.ConnectionManager.cleanup(ConnectionManager.java:379)
   at org.hibernate.jdbc.ConnectionManager.close(ConnectionManager.java:318)
   at org.hibernate.impl.SessionImpl.close(SessionImpl.java:293)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.doClose(SessionFactoryUtils.java:787)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.closeSessionOrRegisterDeferredClose(SessionFactoryUtils.java:775)
   at org.springframework.orm.hibernate3.SessionFactoryUtils.releaseSession(SessionFactoryUtils.java:748)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCleanupAfterCompletion(HibernateTransactionManager.java:662)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.cleanupAfterCompletion(AbstractPlatformTransactionManager.java:750)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:611)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:556)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCloseTransactionAfterThrowing(TransactionAspectSupport.java:284)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:469)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:201)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
09:56:29,845 ERROR [util.transaction.SpringAwareUserTransaction] Application exception overridden by rollback exception
java.lang.Exception
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:469)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:201)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)
09:56:29,845 ERROR [repo.transaction.TransactionUtil] Error rolling back transaction
java.lang.IllegalStateException: Pool not open
   at org.apache.commons.pool.BaseObjectPool.assertOpen(BaseObjectPool.java:78)
   at org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916)
   at org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:80)
   at org.apache.commons.dbcp.PoolingDataSource$PoolGuardConnectionWrapper.close(PoolingDataSource.java:180)
   at org.springframework.orm.hibernate3.LocalDataSourceConnectionProvider.closeConnection(LocalDataSourceConnectionProvider.java:94)
   at org.hibernate.jdbc.ConnectionManager.closeConnection(ConnectionManager.java:445)
   at org.hibernate.jdbc.ConnectionManager.aggressiveRelease(ConnectionManager.java:400)
   at org.hibernate.jdbc.ConnectionManager.afterTransaction(ConnectionManager.java:287)
   at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:205)
   at org.hibernate.transaction.JDBCTransaction.rollback(JDBCTransaction.java:174)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doRollback(HibernateTransactionManager.java:603)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.processRollback(AbstractPlatformTransactionManager.java:579)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.rollback(AbstractPlatformTransactionManager.java:556)
   at org.springframework.transaction.interceptor.TransactionAspectSupport.doCloseTransactionAfterThrowing(TransactionAspectSupport.java:284)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:469)
   at org.alfresco.repo.transaction.TransactionUtil.executeInTransaction(TransactionUtil.java:201)
   at org.alfresco.repo.transaction.TransactionUtil.executeInUserTransaction(TransactionUtil.java:82)
   at org.alfresco.repo.node.index.AbstractReindexComponent.reindex(AbstractReindexComponent.java:221)
   at org.alfresco.repo.node.index.IndexRecoveryJob.execute(IndexRecoveryJob.java:31)
   at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
   at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529)

We rolled back the DB and the file repo (tomcat\alf_data) to yesterday, turned off reindexing and restarted.  It works now, but I was really concerned with it being a Hibernate failure. We don't know the root cause of it, but it appears to be severe.

Right now this is our only disaster recovery procedure that works, and that's not much security for us. Anybody out there have some insight into this?

:shock:

Outcomes