You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@manifoldcf.apache.org by "Karl Wright (Issue Comment Edited) (JIRA)" <ji...@apache.org> on 2011/10/25 08:52:32 UTC
[jira] [Issue Comment Edited] (CONNECTORS-279) Postgresql load test
job delete document cleanup fails sometimes and leaves orphaned documents
[ https://issues.apache.org/jira/browse/CONNECTORS-279?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13134787#comment-13134787 ]
Karl Wright edited comment on CONNECTORS-279 at 10/25/11 6:52 AM:
------------------------------------------------------------------
Pertinent parts of stack dump:
{code}
"Document delete stuffer thread" daemon prio=6 tid=0x04947800 nid=0x119c in Object.wait() [0x06b5f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.manifoldcf.core.lockmanager.LockObject.enterWriteLock(LockObject.java:111)
- locked <0x2c024058> (a org.apache.manifoldcf.core.lockmanager.LockObject)
at org.apache.manifoldcf.core.lockmanager.LockManager.enterWriteCriticalSection(LockManager.java:1459)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.noteModifications(DBInterfacePostgreSQL.java:1322)
at org.apache.manifoldcf.core.database.BaseTable.noteModifications(BaseTable.java:299)
at org.apache.manifoldcf.crawler.jobs.JobQueue.setDeletingStatus(JobQueue.java:718)
at org.apache.manifoldcf.crawler.jobs.JobManager.getNextDeletableDocuments(JobManager.java:1227)
at org.apache.manifoldcf.crawler.system.DocumentDeleteStufferThread.run(DocumentDeleteStufferThread.java:105)
{code}
The thread that is probably holding the lock is:
{code}
"Document delete thread '0'" daemon prio=6 tid=0x04966c00 nid=0x13dc in Object.wait() [0x06baf000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x2c021d08> (a org.apache.manifoldcf.core.database.Database$ExecuteQueryThread)
at java.lang.Thread.join(Thread.java:1196)
at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:453)
at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:505)
at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1152)
at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:168)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performModification(DBInterfacePostgreSQL.java:639)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.reindexTableInternal(DBInterfacePostgreSQL.java:1284)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.noteModifications(DBInterfacePostgreSQL.java:1356)
at org.apache.manifoldcf.core.database.BaseTable.noteModifications(BaseTable.java:299)
at org.apache.manifoldcf.crawler.jobs.JobQueue.deleteIngestedDocumentIdentifiers(JobQueue.java:565)
at org.apache.manifoldcf.crawler.jobs.JobManager.deleteIngestedDocumentIdentifiers(JobManager.java:789)
at org.apache.manifoldcf.crawler.system.DocumentDeleteThread.run(DocumentDeleteThread.java:176)
{code}
The query thread is:
{code}
"Thread-4367355" daemon prio=6 tid=0x04920c00 nid=0x1e88 runnable [0x04bef000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:255)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1165)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191)
- locked <0x2c023e10> (a org.postgresql.core.v3.QueryExecutorImpl)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:337)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:329)
at org.apache.manifoldcf.core.database.Database.execute(Database.java:566)
at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:421)
{code}
So this looks like a case where the PostgreSQL JDBC driver is off chatting with Postgres for the purposes of doing a reindex, but Postgres never responds back. Given that I have no doubt many reindexes have taken place, I wonder why this one is special?
was (Author: kwright@metacarta.com):
Stack dump:
"Document delete stuffer thread" daemon prio=6 tid=0x04947800 nid=0x119c in Object.wait() [0x06b5f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.manifoldcf.core.lockmanager.LockObject.enterWriteLock(LockObject.java:111)
- locked <0x2c024058> (a org.apache.manifoldcf.core.lockmanager.LockObject)
at org.apache.manifoldcf.core.lockmanager.LockManager.enterWriteCriticalSection(LockManager.java:1459)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.noteModifications(DBInterfacePostgreSQL.java:1322)
at org.apache.manifoldcf.core.database.BaseTable.noteModifications(BaseTable.java:299)
at org.apache.manifoldcf.crawler.jobs.JobQueue.setDeletingStatus(JobQueue.java:718)
at org.apache.manifoldcf.crawler.jobs.JobManager.getNextDeletableDocuments(JobManager.java:1227)
at org.apache.manifoldcf.crawler.system.DocumentDeleteStufferThread.run(DocumentDeleteStufferThread.java:105)
The thread that is probably holding the lock is:
"Document delete thread '0'" daemon prio=6 tid=0x04966c00 nid=0x13dc in Object.wait() [0x06baf000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x2c021d08> (a org.apache.manifoldcf.core.database.Database$ExecuteQueryThread)
at java.lang.Thread.join(Thread.java:1196)
at org.apache.manifoldcf.core.database.Database.executeViaThread(Database.java:453)
at org.apache.manifoldcf.core.database.Database.executeUncachedQuery(Database.java:505)
at org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1152)
at org.apache.manifoldcf.core.cachemanager.CacheManager.findObjectsAndExecute(CacheManager.java:144)
at org.apache.manifoldcf.core.database.Database.executeQuery(Database.java:168)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performModification(DBInterfacePostgreSQL.java:639)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.reindexTableInternal(DBInterfacePostgreSQL.java:1284)
at org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.noteModifications(DBInterfacePostgreSQL.java:1356)
at org.apache.manifoldcf.core.database.BaseTable.noteModifications(BaseTable.java:299)
at org.apache.manifoldcf.crawler.jobs.JobQueue.deleteIngestedDocumentIdentifiers(JobQueue.java:565)
at org.apache.manifoldcf.crawler.jobs.JobManager.deleteIngestedDocumentIdentifiers(JobManager.java:789)
at org.apache.manifoldcf.crawler.system.DocumentDeleteThread.run(DocumentDeleteThread.java:176)
The query thread is:
"Thread-4367355" daemon prio=6 tid=0x04920c00 nid=0x1e88 runnable [0x04bef000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:135)
at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:104)
at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
at org.postgresql.core.PGStream.ReceiveChar(PGStream.java:255)
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1165)
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:191)
- locked <0x2c023e10> (a org.postgresql.core.v3.QueryExecutorImpl)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:452)
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:337)
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:329)
at org.apache.manifoldcf.core.database.Database.execute(Database.java:566)
at org.apache.manifoldcf.core.database.Database$ExecuteQueryThread.run(Database.java:421)
So this looks like a case where the PostgreSQL JDBC driver is off chatting with Postgres for the purposes of doing a reindex, but Postgres never responds back. Given that I have no doubt many reindexes have taken place, I wonder why this one is special?
> Postgresql load test job delete document cleanup fails sometimes and leaves orphaned documents
> ----------------------------------------------------------------------------------------------
>
> Key: CONNECTORS-279
> URL: https://issues.apache.org/jira/browse/CONNECTORS-279
> Project: ManifoldCF
> Issue Type: Bug
> Components: Framework crawler agent
> Affects Versions: ManifoldCF 0.4
> Reporter: Karl Wright
> Assignee: Karl Wright
> Fix For: ManifoldCF 0.4
>
>
> Running the postgresql load test on my laptop, I was surprised when the test did not finish. The UI indicated that the job was being deleted, but there were 49,000 documents and that number was not moving. Further inspection yielded the following:
> - Job was in the "DELETING" state
> - Documents were in the "BEINGDELETED" state
> - No activity of any kind ongoing
> The log had no errors.
> It was impossible to get a thread dump, but a cursory inspection of the code indicated that either the documents were being marked as "BEINGDELETED" but were not actually being placed on the in-memory queue, or the delete threads were picking up the documents and somehow avoiding marking them as being processed.
> Also, probably unrelated, the Document Status report listed these documents as having a status of "Being removed" and a state of "Unknown". The "Unknown" should have been a "Deleting". Since the extended WHEN... ELSE clause has a reasonable condition for the "Deleting" answer, it's hard to see how this could have occurred either.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira