manifoldcf-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Karl Wright (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (CONNECTORS-1395) Unexpected jobqueue status - record id 1488898668325, expecting active status, saw 4
Date Wed, 08 Mar 2017 13:28:37 GMT

    [ https://issues.apache.org/jira/browse/CONNECTORS-1395?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15901222#comment-15901222
] 

Karl Wright edited comment on CONNECTORS-1395 at 3/8/17 1:27 PM:
-----------------------------------------------------------------

The ManifoldCF.log file contains the following, which looks like somebody recycled Zookeeper
while the MCF agents process was still running.  This isn't a good idea and will cause carnage
of this kind.  So we need to look elsewhere for the stuck lock.

{code}
ERROR 2017-03-08 00:25:30,433 (Worker thread '14') - Exception tossed: Unexpected jobqueue
status - record id 1488898668325, expecting active status, saw 4
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Unexpected jobqueue status - record
id 1488898668325, expecting active status, saw 4
	at org.apache.manifoldcf.crawler.jobs.JobQueue.updateCompletedRecord(JobQueue.java:1019)
	at org.apache.manifoldcf.crawler.jobs.JobManager.markDocumentCompletedMultiple(JobManager.java:3271)
	at org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:710)
 WARN 2017-03-08 00:25:30,449 (Worker thread '23') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,449 (Worker thread '24') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,464 (Worker thread '9') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,464 (Worker thread '0') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:31,900 (Worker thread '11') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:31,900 (Worker thread '29') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:32,867 (Worker thread '10') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:32,867 (Worker thread '2') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:33,335 (Worker thread '8') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:36,642 (Worker thread '20') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:37,422 (Worker thread '21') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '22') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '3') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '5') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,826 (Worker thread '28') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:39,045 (Worker thread '13') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '4') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '15') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '17') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:46,392 (Worker thread '25') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:46,392 (Worker thread '27') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:11,043 (Worker thread '1') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:35,817 (Worker thread '19') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:35,817 (Worker thread '26') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:36,753 (Worker thread '7') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:39,248 (Worker thread '6') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:39,248 (Worker thread '18') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:43,129 (Worker thread '16') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
FATAL 2017-03-08 00:32:24,819 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawler.system.IdleCleanupThread.run(IdleCleanupThread.java:68)
FATAL 2017-03-08 00:32:29,518 (Stuffer thread) - Error tossed: Can't release lock we don't
hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockObject.clearLock(ZooKeeperLockObject.java:218)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockObject.clearGlobalReadLockNoWait(ZooKeeperLockObject.java:212)
	at org.apache.manifoldcf.core.lockmanager.LockObject.clearGlobalReadLock(LockObject.java:395)
	at org.apache.manifoldcf.core.lockmanager.LockObject.leaveReadLock(LockObject.java:376)
	at org.apache.manifoldcf.core.lockmanager.LockGate.leaveReadLock(LockGate.java:289)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leaveRead(BaseLockManager.java:1359)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leave(BaseLockManager.java:1812)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leaveLocks(BaseLockManager.java:819)
	at org.apache.manifoldcf.core.cachemanager.CacheManager.leaveCache(CacheManager.java:669)
	at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:181)
	at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:204)
	at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performQuery(DBInterfacePostgreSQL.java:862)
	at org.apache.manifoldcf.core.database.BaseTable.performQuery(BaseTable.java:236)
	at org.apache.manifoldcf.crawler.jobs.Jobs.activeJobsPresent(Jobs.java:3171)
	at org.apache.manifoldcf.crawler.jobs.JobManager.getNextDocuments(JobManager.java:2698)
	at org.apache.manifoldcf.crawler.system.StufferThread.run(StufferThread.java:186)
FATAL 2017-03-08 00:34:17,411 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawler.system.IdleCleanupThread.run(IdleCleanupThread.java:68)
FATAL 2017-03-08 00:35:10,734 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawlerui.IdleCleanupThread.run(IdleCleanupThread.java:69)
 WARN 2017-03-08 00:35:56,793 (Startup thread) - Found a long-running query (144672 ms): [UPDATE
jobqueue SET failtime=NULL,checktime=?,failcount=NULL,checkaction=NULL,status=? WHERE jobid=?
AND  (status=? OR status=? OR status=?)]
 WARN 2017-03-08 00:35:57,557 (Startup thread) -   Parameter 0: '0'
 WARN 2017-03-08 00:35:57,557 (Startup thread) -   Parameter 1: 'Z'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 2: '1488898090224'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 3: 'G'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 4: 'U'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 5: 'C'
 WARN 2017-03-08 00:36:09,894 (Startup thread) -  Plan: Update on jobqueue  (cost=0.00..19071.26
rows=23856 width=305)
 WARN 2017-03-08 00:36:09,895 (Startup thread) -  Plan:   ->  Seq Scan on jobqueue  (cost=0.00..19071.26
rows=23856 width=305)
 WARN 2017-03-08 00:36:09,896 (Startup thread) -  Plan:         Filter: ((jobid = 1488898090224::bigint)
AND ((status = 'G'::bpchar) OR (status = 'U'::bpchar) OR (status = 'C'::bpchar)))
 WARN 2017-03-08 00:36:09,896 (Startup thread) - 
 WARN 2017-03-08 00:36:12,998 (Startup thread) -  Stats: n_distinct=2.0 most_common_vals={G,C}
most_common_freqs={0.54030001,0.45969999}
 WARN 2017-03-08 00:36:12,998 (Startup thread) - 
 WARN 2017-03-08 00:36:56,360 (Set priority thread) - Found a long-running query (107269 ms):
[UPDATE jobqueue SET needpriorityprocessid=?,needpriority=? WHERE id=?]
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 0: 'A'
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 1: 'I'
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 2: '1488898711851'
 WARN 2017-03-08 00:36:56,369 (Set priority thread) -  Plan: Update on jobqueue  (cost=0.29..8.30
rows=1 width=281)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) -  Plan:   ->  Index Scan using jobqueue_pkey
on jobqueue  (cost=0.29..8.30 rows=1 width=281)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) -  Plan:         Index Cond: (id = 1488898711851::bigint)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) - 
 WARN 2017-03-08 00:36:56,414 (Set priority thread) -  Stats: n_distinct=2.0 most_common_vals={G,C}
most_common_freqs={0.5388,0.4612}
 WARN 2017-03-08 00:36:56,414 (Set priority thread) - 
FATAL 2017-03-08 00:36:56,798 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.connectorcommon.throttler.ThrottleBin.poll(ThrottleBin.java:334)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler$ThrottlingGroup.poll(Throttler.java:952)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler$ThrottlingGroups.poll(Throttler.java:290)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler.poll(Throttler.java:165)
	at org.apache.manifoldcf.connectorcommon.throttler.ThrottleGroups.poll(ThrottleGroups.java:114)
	at org.apache.manifoldcf.connectorcommon.interfaces.ThrottleGroupsFactory$ThrottlerPoll.doPoll(ThrottleGroupsFactory.java:65)
	at org.apache.manifoldcf.core.system.ManifoldCF.pollAll(ManifoldCF.java:1476)
	at org.apache.manifoldcf.agents.system.IdleCleanupThread.run(IdleCleanupThread.java:93)
{code}



was (Author: kwright@metacarta.com):
The ManifoldCF.log file contains:

{code}
ERROR 2017-03-08 00:25:30,433 (Worker thread '14') - Exception tossed: Unexpected jobqueue
status - record id 1488898668325, expecting active status, saw 4
org.apache.manifoldcf.core.interfaces.ManifoldCFException: Unexpected jobqueue status - record
id 1488898668325, expecting active status, saw 4
	at org.apache.manifoldcf.crawler.jobs.JobQueue.updateCompletedRecord(JobQueue.java:1019)
	at org.apache.manifoldcf.crawler.jobs.JobManager.markDocumentCompletedMultiple(JobManager.java:3271)
	at org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:710)
 WARN 2017-03-08 00:25:30,449 (Worker thread '23') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,449 (Worker thread '24') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,464 (Worker thread '9') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:30,464 (Worker thread '0') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:31,900 (Worker thread '11') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:31,900 (Worker thread '29') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:32,867 (Worker thread '10') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:32,867 (Worker thread '2') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:33,335 (Worker thread '8') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:36,642 (Worker thread '20') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:37,422 (Worker thread '21') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '22') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '3') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,280 (Worker thread '5') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:38,826 (Worker thread '28') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:39,045 (Worker thread '13') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '4') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '15') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:45,425 (Worker thread '17') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:46,392 (Worker thread '25') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:25:46,392 (Worker thread '27') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:11,043 (Worker thread '1') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:35,817 (Worker thread '19') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:35,817 (Worker thread '26') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:36,753 (Worker thread '7') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:39,248 (Worker thread '6') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:39,248 (Worker thread '18') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
 WARN 2017-03-08 00:26:43,129 (Worker thread '16') - Service interruption reported for job
1488898090224 connection 'web': Job no longer active
FATAL 2017-03-08 00:32:24,819 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawler.system.IdleCleanupThread.run(IdleCleanupThread.java:68)
FATAL 2017-03-08 00:32:29,518 (Stuffer thread) - Error tossed: Can't release lock we don't
hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockObject.clearLock(ZooKeeperLockObject.java:218)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockObject.clearGlobalReadLockNoWait(ZooKeeperLockObject.java:212)
	at org.apache.manifoldcf.core.lockmanager.LockObject.clearGlobalReadLock(LockObject.java:395)
	at org.apache.manifoldcf.core.lockmanager.LockObject.leaveReadLock(LockObject.java:376)
	at org.apache.manifoldcf.core.lockmanager.LockGate.leaveReadLock(LockGate.java:289)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leaveRead(BaseLockManager.java:1359)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leave(BaseLockManager.java:1812)
	at org.apache.manifoldcf.core.lockmanager.BaseLockManager.leaveLocks(BaseLockManager.java:819)
	at org.apache.manifoldcf.core.cachemanager.CacheManager.leaveCache(CacheManager.java:669)
	at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:181)
	at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:204)
	at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performQuery(DBInterfacePostgreSQL.java:862)
	at org.apache.manifoldcf.core.database.BaseTable.performQuery(BaseTable.java:236)
	at org.apache.manifoldcf.crawler.jobs.Jobs.activeJobsPresent(Jobs.java:3171)
	at org.apache.manifoldcf.crawler.jobs.JobManager.getNextDocuments(JobManager.java:2698)
	at org.apache.manifoldcf.crawler.system.StufferThread.run(StufferThread.java:186)
FATAL 2017-03-08 00:34:17,411 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawler.system.IdleCleanupThread.run(IdleCleanupThread.java:68)
FATAL 2017-03-08 00:35:10,734 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool$Pool.pollAll(ConnectorPool.java:590)
	at org.apache.manifoldcf.core.connectorpool.ConnectorPool.pollAllConnectors(ConnectorPool.java:338)
	at org.apache.manifoldcf.crawler.repositoryconnectorpool.RepositoryConnectorPool.pollAllConnectors(RepositoryConnectorPool.java:124)
	at org.apache.manifoldcf.crawlerui.IdleCleanupThread.run(IdleCleanupThread.java:69)
 WARN 2017-03-08 00:35:56,793 (Startup thread) - Found a long-running query (144672 ms): [UPDATE
jobqueue SET failtime=NULL,checktime=?,failcount=NULL,checkaction=NULL,status=? WHERE jobid=?
AND  (status=? OR status=? OR status=?)]
 WARN 2017-03-08 00:35:57,557 (Startup thread) -   Parameter 0: '0'
 WARN 2017-03-08 00:35:57,557 (Startup thread) -   Parameter 1: 'Z'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 2: '1488898090224'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 3: 'G'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 4: 'U'
 WARN 2017-03-08 00:35:57,558 (Startup thread) -   Parameter 5: 'C'
 WARN 2017-03-08 00:36:09,894 (Startup thread) -  Plan: Update on jobqueue  (cost=0.00..19071.26
rows=23856 width=305)
 WARN 2017-03-08 00:36:09,895 (Startup thread) -  Plan:   ->  Seq Scan on jobqueue  (cost=0.00..19071.26
rows=23856 width=305)
 WARN 2017-03-08 00:36:09,896 (Startup thread) -  Plan:         Filter: ((jobid = 1488898090224::bigint)
AND ((status = 'G'::bpchar) OR (status = 'U'::bpchar) OR (status = 'C'::bpchar)))
 WARN 2017-03-08 00:36:09,896 (Startup thread) - 
 WARN 2017-03-08 00:36:12,998 (Startup thread) -  Stats: n_distinct=2.0 most_common_vals={G,C}
most_common_freqs={0.54030001,0.45969999}
 WARN 2017-03-08 00:36:12,998 (Startup thread) - 
 WARN 2017-03-08 00:36:56,360 (Set priority thread) - Found a long-running query (107269 ms):
[UPDATE jobqueue SET needpriorityprocessid=?,needpriority=? WHERE id=?]
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 0: 'A'
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 1: 'I'
 WARN 2017-03-08 00:36:56,360 (Set priority thread) -   Parameter 2: '1488898711851'
 WARN 2017-03-08 00:36:56,369 (Set priority thread) -  Plan: Update on jobqueue  (cost=0.29..8.30
rows=1 width=281)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) -  Plan:   ->  Index Scan using jobqueue_pkey
on jobqueue  (cost=0.29..8.30 rows=1 width=281)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) -  Plan:         Index Cond: (id = 1488898711851::bigint)
 WARN 2017-03-08 00:36:56,370 (Set priority thread) - 
 WARN 2017-03-08 00:36:56,414 (Set priority thread) -  Stats: n_distinct=2.0 most_common_vals={G,C}
most_common_freqs={0.5388,0.4612}
 WARN 2017-03-08 00:36:56,414 (Set priority thread) - 
FATAL 2017-03-08 00:36:56,798 (Idle cleanup thread) - Error tossed: Can't release lock we
don't hold
java.lang.IllegalStateException: Can't release lock we don't hold
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperConnection.releaseLock(ZooKeeperConnection.java:815)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.leaveServiceRegistryLock(ZooKeeperLockManager.java:575)
	at org.apache.manifoldcf.core.lockmanager.ZooKeeperLockManager.scanServiceData(ZooKeeperLockManager.java:351)
	at org.apache.manifoldcf.connectorcommon.throttler.ThrottleBin.poll(ThrottleBin.java:334)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler$ThrottlingGroup.poll(Throttler.java:952)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler$ThrottlingGroups.poll(Throttler.java:290)
	at org.apache.manifoldcf.connectorcommon.throttler.Throttler.poll(Throttler.java:165)
	at org.apache.manifoldcf.connectorcommon.throttler.ThrottleGroups.poll(ThrottleGroups.java:114)
	at org.apache.manifoldcf.connectorcommon.interfaces.ThrottleGroupsFactory$ThrottlerPoll.doPoll(ThrottleGroupsFactory.java:65)
	at org.apache.manifoldcf.core.system.ManifoldCF.pollAll(ManifoldCF.java:1476)
	at org.apache.manifoldcf.agents.system.IdleCleanupThread.run(IdleCleanupThread.java:93)
{code}


> Unexpected jobqueue status - record id 1488898668325, expecting active status, saw 4
> ------------------------------------------------------------------------------------
>
>                 Key: CONNECTORS-1395
>                 URL: https://issues.apache.org/jira/browse/CONNECTORS-1395
>             Project: ManifoldCF
>          Issue Type: Bug
>          Components: Framework core
>    Affects Versions: ManifoldCF 2.6
>            Reporter: Karl Wright
>            Assignee: Karl Wright
>             Fix For: ManifoldCF 2.7
>
>
> User saw this in the log, after which the system hung:
> {code}
> ERROR 2017-03-08 00:25:30,433 (Worker thread '14') - Exception tossed: Unexpected jobqueue
status - record id 1488898668325, expecting active status, saw 4
> org.apache.manifoldcf.core.interfaces.ManifoldCFException: Unexpected jobqueue status
- record id 1488898668325, expecting active status, saw 4
>                 at org.apache.manifoldcf.crawler.jobs.JobQueue.updateCompletedRecord(JobQueue.java:1019)
>                 at org.apache.manifoldcf.crawler.jobs.JobManager.markDocumentCompletedMultiple(JobManager.java:3271)
>                 at org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:710)
> WARN 2017-03-08 00:25:30,449 (Worker thread '23') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:30,449 (Worker thread '24') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:30,464 (Worker thread '9') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:30,464 (Worker thread '0') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:31,900 (Worker thread '11') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:31,900 (Worker thread '29') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:32,867 (Worker thread '10') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:32,867 (Worker thread '2') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:33,335 (Worker thread '8') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:36,642 (Worker thread '20') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:37,422 (Worker thread '21') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:38,280 (Worker thread '22') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:38,280 (Worker thread '3') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:38,280 (Worker thread '5') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:38,826 (Worker thread '28') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:39,045 (Worker thread '13') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:45,425 (Worker thread '4') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:45,425 (Worker thread '15') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:45,425 (Worker thread '17') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:46,392 (Worker thread '25') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:25:46,392 (Worker thread '27') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:11,043 (Worker thread '1') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:35,817 (Worker thread '19') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:35,817 (Worker thread '26') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:36,753 (Worker thread '7') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:39,248 (Worker thread '6') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:39,248 (Worker thread '18') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> WARN 2017-03-08 00:26:43,129 (Worker thread '16') - Service interruption reported for
job 1488898090224 connection 'web': Job no longer active
> FATAL 2017-03-08 00:32:24,819 (Idle cleanup thread) - Error tossed: Can't release lock
we don't hold
> java.lang.IllegalStateException: Can't release lock we don't hold”
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

Mime
View raw message