[jira] [Commented] (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=13133852#comment-13133852 ] Karl Wright commented on CONNECTORS-279: I entered another ticket, CONNECTORS-280, for the reporting issues. > 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
[jira] [Commented] (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=13133854#comment-13133854 ] Karl Wright commented on CONNECTORS-279: I have not yet been able to make this failure happen when I run outside of ant. But under ant, on my laptop, I was able to make it happen also with the rss test. The rss test failure had a somewhat different signature in that it looked like the document delete stuffer thread had just given up and frozen or exited, leaving lots of documents in the ELIGIBLEFORDELETE state. > 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
[jira] [Commented] (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 commented on CONNECTORS-279: 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 > -- > > Ke
[jira] [Commented] (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=13134788#comment-13134788 ] Karl Wright commented on CONNECTORS-279: I'm going to try updating the JDBC driver to the latest one and see what that yields. > 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
[jira] [Commented] (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=13134796#comment-13134796 ] Karl Wright commented on CONNECTORS-279: Postgresql logging shows nothing unusual at the time the reindex fails to complete. > 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
[jira] [Commented] (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=13135407#comment-13135407
]
Karl Wright commented on CONNECTORS-279:
With the 9.1 JDBC driver, things are even worse. The crawl does not complete
because 3 queries seem to get forever "stuck". They are not the same query
either:
{code}
"Worker thread '16'" daemon prio=6 tid=0x0547f000 nid=0x1b90 in Object.wait()
[0x0609f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x29c514c0> (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.DBInterfacePostgreSQL.startATransaction(DBInterfacePostgreSQL.java:1134)
at
org.apache.manifoldcf.core.database.Database.internalTransactionBegin(Database.java:235)
at
org.apache.manifoldcf.core.database.Database.synchronizeTransactions(Database.java:218)
at
org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1140)
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.beginTransaction(DBInterfacePostgreSQL.java:1072)
at
org.apache.manifoldcf.crawler.jobs.JobManager.finishDocuments(JobManager.java:3902)
at
org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:567)
{code}
{code}
"Worker thread '12'" daemon prio=6 tid=0x0547d800 nid=0x1170 in Object.wait()
[0x05f5f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1143)
- locked <0x29c51608> (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.DBInterfacePostgreSQL.startATransaction(DBInterfacePostgreSQL.java:1134)
at
org.apache.manifoldcf.core.database.Database.internalTransactionBegin(Database.java:235)
at
org.apache.manifoldcf.core.database.Database.synchronizeTransactions(Database.java:218)
at
org.apache.manifoldcf.core.database.Database$QueryCacheExecutor.create(Database.java:1140)
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.performQuery(DBInterfacePostgreSQL.java:811)
at
org.apache.manifoldcf.core.database.BaseTable.performQuery(BaseTable.java:229)
at
org.apache.manifoldcf.agents.incrementalingest.IncrementalIngester.noteDocumentIngest(IncrementalIngester.java:1358)
at
org.apache.manifoldcf.agents.incrementalingest.IncrementalIngester.performIngestion(IncrementalIngester.java:495)
at
org.apache.manifoldcf.agents.incrementalingest.IncrementalIngester.documentIngest(IncrementalIngester.java:364)
at
org.apache.manifoldcf.crawler.system.WorkerThread$ProcessActivity.ingestDocument(WorkerThread.java:1577)
at
org.apache.manifoldcf.crawler.connectors.rss.RSSConnector.processDocuments(RSSConnector.java:1470)
at
org.apache.manifoldcf.crawler.system.WorkerThread.run(WorkerThread.java:561)
{code}
> 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 er
[jira] [Commented] (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=13137766#comment-13137766 ] Karl Wright commented on CONNECTORS-279: Posted to both stackoverflow and postgresql-general lists. Other people on the postgresql lists seem to have encountered this but no resolution as yet appears to be available. It doesn't seem like the postgresql team is taking it seriously. > 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
[jira] [Commented] (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=13138221#comment-13138221
]
Karl Wright commented on CONNECTORS-279:
Postgresql team responded and gave debugging tips, which show the following:
{code}
postgres=# select * from pg_locks;
locktype| database | relation | page | tuple | virtualxid | transactionid
| classid | objid | objsubid | virtualtransaction | pid | mode | g
ranted
---+--+--+--+---++--
-+-+---+--++--+--+--
---
relation | 133853 | 140809 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140809 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140807 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140807 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
virtualxid| | | | | 2/204727 |
| | | | 2/204727 | 7260 | ExclusiveLock| t
virtualxid| | | | | 3/185434 |
| | | | 3/185434 | 2384 | ExclusiveLock| t
virtualxid| | | | | 1/216105 |
| | | | 1/216105 | 1800 | ExclusiveLock| t
relation | 133853 | 140751 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140745 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140810 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140810 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140808 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140808 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140812 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140812 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140784 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140785 | | ||
| | | | 1/216105 | 1800 | ShareLock| f
relation | 133853 | 140791 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140791 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140785 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140785 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
transactionid | | | | || 6252988
| | | | 2/204727 | 7260 | ExclusiveLock| t
relation | 133853 | 140811 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140811 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation | 133853 | 140813 | | ||
| | | | 2/204727 | 7260 | AccessShareLock | t
relation | 133853 | 140813 | | ||
| | | | 2/204727 | 7260 | RowExclusiveLock | t
relation |11564 |10969 | | ||
| | | | 3/185434 | 2384 | AccessShareLock | t
(27 rows)
postgres=# select * from pg_stat_activity;
datid | datname | procpid | usesysid | usename | current_query
| waiting | xact_start |query_start |
backend_start| client_addr | client_port
+
