Hi, When you restart a job, or restart the agents process, ManifoldCF has to bash the states of all the jobqueue records to correct values. This is unfortunately time consuming. But I have found no way to avoid it.
Thanks, Karl On Mon, Aug 31, 2015 at 11:17 AM, Roman Šitina <[email protected]> wrote: > Hello, > > we can see a lot of these line in our logs when we restart a job. > > ARN 2015-08-31 13:28:16,789 (Set priority thread) - > WARN 2015-08-31 13:32:43,203 (Startup thread) - Found a long-running > query (181072 ms): [UPDATE jobqueue SET > failcount=NULL,checktime=?,checkaction=?,failtime=NULL WHERE jobid=? > AND (status=? OR status=?)] > WARN 2015-08-31 13:32:43,203 (Startup thread) - Parameter 0: '0' > WARN 2015-08-31 13:32:43,203 (Startup thread) - Parameter 1: 'R' > WARN 2015-08-31 13:32:43,203 (Startup thread) - Parameter 2: > '1440693578140' > WARN 2015-08-31 13:32:43,203 (Startup thread) - Parameter 3: 'G' > WARN 2015-08-31 13:32:43,203 (Startup thread) - Parameter 4: 'P' > WARN 2015-08-31 13:32:43,204 (Startup thread) - Plan: Seq Scan on > jobqueue (cost=0.00..118691.83 rows=3304553 width=244) > WARN 2015-08-31 13:32:43,204 (Startup thread) - Plan: Filter: > ((jobid = 1440693578140::bigint) AND ((status = 'G'::bpchar) OR > (status = 'P'::bpchar))) > WARN 2015-08-31 13:32:43,204 (Startup thread) - > WARN 2015-08-31 13:32:43,209 (Startup thread) - Stats: n_distinct=3.0 > most_common_vals={P,G,C} > most_common_freqs={0.96696669,0.027633334,0.0054000001} > WARN 2015-08-31 13:32:43,209 (Startup thread) - > WARN 2015-08-31 13:40:53,834 (Set priority thread) - Found a > long-running query (74803 ms): [SELECT needpriority FROM jobqueue > WHERE id=? FOR UPDATE] > WARN 2015-08-31 13:40:53,834 (Startup thread) - Found a long-running > query (420589 ms): [UPDATE jobqueue SET > failcount=NULL,checktime=?,checkaction=?,failtime=NULL WHERE jobid=? > AND (status=? OR status=?)] > WARN 2015-08-31 13:40:53,835 (Set priority thread) - Parameter 0: > '1440696241299' > WARN 2015-08-31 13:40:53,835 (Startup thread) - Parameter 0: '0' > WARN 2015-08-31 13:40:53,835 (Startup thread) - Parameter 1: 'R' > WARN 2015-08-31 13:40:53,835 (Startup thread) - Parameter 2: > '1440693578140' > WARN 2015-08-31 13:40:53,835 (Startup thread) - Parameter 3: 'G' > WARN 2015-08-31 13:40:53,835 (Startup thread) - Parameter 4: 'P' > WARN 2015-08-31 13:40:53,836 (Set priority thread) - Plan: Index Scan > using jobqueue_pkey on jobqueue (cost=0.00..9.03 rows=1 width=8) > (actual time=0.012..0.035 rows=1 loops=1) > WARN 2015-08-31 13:40:53,836 (Set priority thread) - Plan: Index > Cond: (id = 1440696241299::bigint) > WARN 2015-08-31 13:40:53,836 (Set priority thread) - Plan: Total > runtime: 0.060 ms > WARN 2015-08-31 13:40:53,836 (Set priority thread) - > WARN 2015-08-31 13:40:53,837 (Startup thread) - Plan: Seq Scan on > jobqueue (cost=0.00..152542.58 rows=1732985 width=244) > WARN 2015-08-31 13:40:53,838 (Startup thread) - Plan: Filter: > ((jobid = 1440693578140::bigint) AND ((status = 'G'::bpchar) OR > (status = 'P'::bpchar))) > WARN 2015-08-31 13:40:53,838 (Startup thread) - > WARN 2015-08-31 13:40:53,841 (Set priority thread) - Stats: > n_distinct=3.0 most_common_vals={P,G,C} > most_common_freqs={0.91589999,0.071966663,0.012133333} > WARN 2015-08-31 13:40:53,841 (Set priority thread) - > WARN 2015-08-31 13:40:53,842 (Startup thread) - Stats: n_distinct=3.0 > most_common_vals={P,G,C} > most_common_freqs={0.91589999,0.071966663,0.012133333} > WARN 2015-08-31 13:40:53,842 (Startup thread) - > ERROR 2015-08-31 13:40:57,313 (Startup thread) - Exception tossed: > ERROR: deadlock detected > Detail: Process 1152 waits for ShareLock on transaction 458210; > blocked by process 7617. > Process 7617 waits for ShareLock on transaction 458208; blocked by process > 1152. > Hint: See server log for query details. > org.apache.manifoldcf.core.interfaces.ManifoldCFException: ERROR: > deadlock detected > Detail: Process 1152 waits for ShareLock on transaction 458210; > blocked by process 7617. > Process 7617 waits for ShareLock on transaction 458208; blocked by process > 1152. > Hint: See server log for query details. > at > org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.reinterpretException(DBInterfacePostgreSQL.java:631) > at > org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performModification(DBInterfacePostgreSQL.java:663) > at > org.apache.manifoldcf.core.database.DBInterfacePostgreSQL.performUpdate(DBInterfacePostgreSQL.java:254) > > > - Version of Postgres: 8.4.20 > - Machine: Amazon r3.xlarge - 4 CPU, 30.5 GiB Mem, 1x 80 GB storage > > - Number of records in jobqueue is around 1.7 million. > > - Job synchronisation is over Zookeeper. > > - I set all the recommended setting found here: > > https://manifoldcf.apache.org/release/trunk/en_US/how-to-build-and-deploy.html#Configuring+a+PostgreSQL+database > > - Vacuum and reindex is scheduled daily. > > Are these query times as expected? Is there anything we can tweak to > speed up Postgres? What about these deadlocks - is that something > which happens time to time? > > Thanks for your hints > > Roman >
