admin and other logins don't work - indexing issue

As we transition to the new Hyland Community, some post links may be temporarily disrupted as we finalize redirects. We apologize for the inconvenience and are working to resolve this as quickly as possible. Details.

aatamer

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:

derek

Hi,

You'd feel much more secure if you were an Enterprise customer.  However, the [WARNING] Unknown Ptg is probably just the POI library (office document transformation) issuing pointless warnings.   The Hibernate issue is really just the DBCP connection pool not being open.  Read up on the DBCP connection pool configuration options.

Regards