[
https://issues.apache.org/jira/browse/CONNECTORS-1592?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16813384#comment-16813384
]
roel goovaerts commented on CONNECTORS-1592:
--------------------------------------------
Hi Karl,
We've had some time to analyze and debug in detail. First of all we ran the
databasemaintenance script when manifold was shut down; after a restart and 2
hours of crawling it started to log long-running queries again.
While monitoring, we noticed that there are frequent locks following queries;
normally these logs are resolved quickly (as yo uwould expect). But every once
in a while the locks start stacking up until postgres is using 100% of cpu and
is shown as being idle and manifold is idle as well. After a while things pick
up again and manifold starts logging long-running queries.
SELECT_blocked_queries.txt contains a incomplete list of queries that are
blocked by another process. This list was captured at a time we were monitoring
such an inactive moment.
When looking into the tables created in postgres we saw that jobID is a primary
key of the jobs table, and this is a foreign key for the intrinsiclink-table
and jobqueue-table. There are 21 entries in the job-table and 1400+ entries in
the jobQueue-table.
>From our analysis we have some hypothesis:
- one 'root' query doesn't get committed, this keeps a lock on the job-,
intrinsiclink- or jobQueue-table and cascades into the bulk of locked queries.
Main question here is how one query could get stuck; can a query be waiting for
something from manifold until it is committed?
- there is a locking conflict that arises from the jobID being a foreing key
constraint for both the jobQueue and intrinsiclinks. From debugging we have the
impression that postgres locks the whole intrinsiclink-table in a query which
is specified to have one specific jobId.
Your input in this issue would be appreciated.
Based on the "performance tuning" and "building ManifoldCF" resources we have
verified our properties to be in the correct database limits; The only thing we
were wondering, concerning the formula 'manifoldcf_db_pool_size *
number_of_manifoldcf_processes <= maximum_postgresql_database_handles - 2', is
if manifold_db_pool_size is postgres.max_connections?
some additional questions:
- could using the multi process-functionality of
org.apache.manifoldcf.usejettyparentclassloader be used to improve this issue?
- I have read that disabling swap can be good for intensive db-interactions; do
you have experience with disabling swap improving manifold?
- is there a possibility that we could set-up a conference call with someone
from the manifold team?
Many thanks for your time.
> Found long running query in manifold scheduled job
> --------------------------------------------------
>
> Key: CONNECTORS-1592
> URL: https://issues.apache.org/jira/browse/CONNECTORS-1592
> Project: ManifoldCF
> Issue Type: Bug
> Affects Versions: ManifoldCF 2.12
> Reporter: Subasini Rath
> Priority: Major
> Attachments: LongRunningWithPlan_thread39.txt,
> SELECT_blocked_queries.txt, postgresql.conf, properties.xml
>
>
> Hi Karl,
> I am also facing the above mentioned issue. (Similar to Connector-880)
> I am using manifold2.12 binary version. I am using Solr output connector and
> Web repository connection. Manifold is using all default configuration.
> When I am running the jobs manually, it runs fine. Same jobs have been
> scheduled to run everyday.
> I am getting below exceptions and the job gets hanged/ going to waiting stage.
> Could you please help me in resolving the same.
> I am getting the below error -
> Scenario-1
> WARN 2019-03-08T23:58:20,338 (qtp550147359-413) - Found a long-running query
> (2706114 ms): [SELECT
> t0.id,t0.description,t0.status,t0.starttime,t0.endtime,t0.errortext FROM jobs
> t0 ORDER BY description ASC]
> WARN 2019-03-08T23:58:20,337 (Document delete stuffer thread) - Found a
> long-running query (2737370 ms): [SELECT id FROM jobs WHERE status=? LIMIT 1]
> WARN 2019-03-08T23:58:20,339 (Job reset thread) - Found a long-running query
> (2770133 ms): [SELECT id FROM jobs WHERE status IN (?,?)]
> WARN 2019-03-08T23:58:20,386 (Document delete stuffer thread) - Parameter 0:
> 'e'
> WARN 2019-03-08T23:58:20,337 (Set priority thread) - Found a long-running
> query (2732379 ms): [SELECT id,dochash,docid,jobid FROM jobqueue WHERE
> needpriority=? LIMIT 1000]
> WARN 2019-03-08T23:58:20,386 (Set priority thread) - Parameter 0: 'T'
> WARN 2019-03-08T23:58:20,386 (Job reset thread) - Parameter 0: 'I'
> WARN 2019-03-08T23:58:20,386 (Job reset thread) - Parameter 1: 'i'
> WARN 2019-03-08T23:58:20,372 (Seeding thread) - Parameter 2: '1552047176062'
> WARN 2019-03-08T23:58:20,474 (Document cleanup stuffer thread) - Found a
> long-running query (2737524 ms): [SELECT id FROM jobs WHERE status=? LIMIT 1]
> WARN 2019-03-08T23:58:20,474 (Document cleanup stuffer thread) - Parameter
> 0: 'S'
> WARN 2019-03-08T23:58:20,474 (Finisher thread) - Found a long-running query
> (2752034 ms): [SELECT id FROM jobs WHERE status IN (?,?,?) FOR UPDATE]
> WARN 2019-03-08T23:58:20,474 (Finisher thread) - Parameter 0: 'A'
> WARN 2019-03-08T23:58:20,475 (Finisher thread) - Parameter 1: 'W'
> WARN 2019-03-08T23:58:20,475 (Finisher thread) - Parameter 2: 'R'
> WARN 2019-03-08T23:58:20,475 (Delete startup thread) - Found a long-running
> query (2752036 ms): [SELECT id FROM jobs WHERE status=? FOR UPDATE]
> WARN 2019-03-08T23:58:20,475 (Delete startup thread) - Parameter 0: 'E'
> WARN 2019-03-08T23:58:20,483 (qtp550147359-4339) - Found a long-running
> query (2496641 ms): [SELECT
> t0.id,t0.description,t0.status,t0.starttime,t0.endtime,t0.errortext FROM jobs
> t0 ORDER BY description ASC]
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan:
> isDistinctSelect=[false]
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan: isGrouped=[false]
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan: isAggregated=[false]
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan: columns=[ COLUMN:
> PUBLIC.JOBS.ID not nullable
> WARN 2019-03-08T23:58:20,492 (qtp550147359-4346) - Found a long-running
> query (2435908 ms): [SELECT
> t0.id,t0.description,t0.status,t0.starttime,t0.endtime,t0.errortext FROM jobs
> t0 ORDER BY description ASC]
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan:
> WARN 2019-03-08T23:58:20,492 (Finisher thread) - Plan: ]
> WARN 2019-03-08T23:58:20,499 (Finisher thread) - Plan: [range variable 1
> WARN 2019-03-08T23:58:20,499 (Finisher thread) - Plan: join type=INNER
> WARN 2019-03-08T23:58:20,499 (Finisher thread) - Plan: table=SYSTEM_SUBQUERY
> WARN 2019-03-08T23:58:20,499 (Finisher thread) - Plan: cardinality=0
> WARN 2019-03-08T23:58:20,499 (Finisher thread) - Plan: access=FULL SCAN
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: join condition =
> [index=SYS_IDX_13329
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: ]
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: ][range variable 2
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: join type=INNER
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: table=JOBS
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: cardinality=3
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: access=INDEX PRED
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: join condition =
> [index=I1549955498033
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: start conditions=[
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: EQUAL arg_left=[
> COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: ] arg_right=[ COLUMN:
> C1
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: end condition=[
> WARN 2019-03-08T23:58:20,500 (Finisher thread) - Plan: EQUAL arg_left=[
> COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ] arg_right=[ COLUMN:
> C1
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: other condition=[
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: EQUAL arg_left=[
> COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ] arg_right=[ COLUMN:
> C1
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: PARAMETERS=[
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: @0[DYNAMIC PARAM: ,
> TYPE = VARCHAR
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: @1[DYNAMIC PARAM: ,
> TYPE = VARCHAR
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: @2[DYNAMIC PARAM: ,
> TYPE = VARCHAR
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: SUBQUERIES[
> WARN 2019-03-08T23:58:20,501 (Finisher thread) - Plan: [level=1
> WARN 2019-03-08T23:58:20,502 (Finisher thread) - Plan: value expression]]
> WARN 2019-03-08T23:58:20,502 (Finisher thread) -
> WARN 2019-03-08T23:58:20,504 (Delete startup thread) - Plan:
> isDistinctSelect=[false]
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan:
> isGrouped=[false]
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan:
> isAggregated=[false]
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: columns=[
> COLUMN: PUBLIC.JOBS.ID not nullable
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan:
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: ]
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: [range variable
> 1
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: join type=INNER
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: table=JOBS
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: cardinality=3
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: access=INDEX
> PRED
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: join condition
> = [index=I1549955498033
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: start
> conditions=[
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: EQUAL
> arg_left=[ COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,505 (Delete startup thread) - Plan: ] arg_right=[
> DYNAMIC PARAM: , TYPE = CHARACTER
> WARN 2019-03-08T23:58:20,507 (Delete startup thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> isDistinctSelect=[false]
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> isGrouped=[false]
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> isAggregated=[false]
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> columns=[ COLUMN: PUBLIC.JOBS.ID not nullable
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: ]
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> [range variable 1
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: join
> type=INNER
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> table=JOBS
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> cardinality=3
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan:
> access=INDEX PRED
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: join
> condition = [index=I1549955498033
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: start
> conditions=[
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: EQUAL
> arg_left=[ COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,507 (Delete startup thread) - Plan: end condition=[
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: ]
> arg_right=[ DYNAMIC PARAM: , TYPE = CHARACTER
> WARN 2019-03-08T23:58:20,507 (Document cleanup stuffer thread) - Plan: ]]
> WARN 2019-03-08T23:58:20,507 (Delete startup thread) - Plan: EQUAL
> arg_left=[ COLUMN: PUBLIC.JOBS.STATUS
> WARN 2019-03-08T23:58:20,508 (Document cleanup stuffer thread) - Plan: end
> condition=[
> WARN 2019-03-08T23:58:20,508 (Delete startup thread) - Plan: ] arg_right=[
> DYNAMIC PARAM: , TYPE = CHARACTER
> WARN 2019-03-08T23:58:20,508 (Document cleanup stuffer thread) - Plan: EQUAL
> arg_left=[ COLUMN: PUBLIC.JOBS.STATUS
>
> Scenario-2
> WEB: Illegal seed URL
> 'http://intranet.abcde.com/wps/wcm/connect/xxx/xxxwebsite/home
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
