You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@manifoldcf.apache.org by Aeham Abushwashi <ae...@exonar.com> on 2014/12/15 01:40:38 UTC

Re: Scaling in MCF

Hi Karl,

I have some analysis to share wrt job starting performance...

After starting a handful of new jobs, my 3-node mcf cluster (dev_1x and
already populated with ~10M jobqueue records) appeared to have stalled. The
stuffer threads on two nodes were waiting on the stuffer lock. The stuffer
thread on the third node was blocked on the execution of the sql query in
JobQueue#updateActiveRecord.

My guess is that as the stuffer thread picks up items and updates their
status and process id, it can get blocked (indirectly?) by the
repriotisation query issued when a job is started. This causes the stuffer
thread to stall and subsequently no documents are processed by any node in
the cluster.

Below is a dump of the pg_stat_activity table. Note the values of the
'waiting' column (true/false). The second row corresponds to the query
invoked by JobQueue#updateActiveRecord

 datid  |   datname   |  pid  | usesysid | usename  | application_name |
client_addr | client_hostname | client_port |         backend_start
|          xact_start           |          query_start          |
state_change
        | waiting | state
|                                                         query
--------+-------------+-------+----------+----------+------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-----------------------
--------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
 400109 | crawlerperf | 16001 |    16384 | slurp    |                  |
10.250.0.23 |                 |       52790 | 2014-12-14 23:19:25.909125+00
| 2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  |
2014-12-14 23:51:29.44
226+00  | t       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
 400109 | crawlerperf | 17020 |    16384 | slurp    |                  |
10.250.0.23 |                 |       52813 | 2014-12-14 23:44:31.286417+00
| 2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 |
2014-12-15 00:09:15.16
1376+00 | t       | active | UPDATE jobqueue SET status=$1,processid=$2
WHERE id=$3
 400109 | crawlerperf | 16744 |    16384 | slurp    |                  |
10.250.0.23 |                 |       52807 | 2014-12-14 23:37:22.181826+00
|                               | 2014-12-15 00:16:51.936374+00 |
2014-12-15 00:16:51.93
6374+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
 400109 | crawlerperf | 17022 |    16384 | slurp    |                  |
10.250.0.23 |                 |       52815 | 2014-12-14 23:44:31.402114+00
|                               | 2014-12-15 00:16:52.176358+00 |
2014-12-15 00:16:52.17
6402+00 | f       | idle   | SELECT * FROM agents
 400109 | crawlerperf | 14258 |    16384 | slurp    |                  |
10.250.0.33 |                 |       55885 | 2014-12-14 22:43:56.316824+00
| 2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 |
2014-12-15 00:03:43.59
3023+00 | t       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
 400109 | crawlerperf | 13832 |    16384 | slurp    |                  |
10.250.0.33 |                 |       55882 | 2014-12-14 22:30:47.752513+00
|                               | 2014-12-15 00:16:48.157249+00 |
2014-12-15 00:16:48.15
7249+00 | f       | idle   | SELECT * FROM agents
 400109 | crawlerperf | 17745 |    16384 | slurp    |                  |
10.250.0.33 |                 |       55901 | 2014-12-14 23:56:01.490378+00
| 2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 |
2014-12-15 00:16:54.55
0777+00 | f       | active | SELECT id,dochash,docid,jobid FROM jobqueue
WHERE needpriority=$1 LIMIT 1000
 400109 | crawlerperf | 16992 |    16384 | slurp    |                  |
10.250.0.43 |                 |       51521 | 2014-12-14 23:43:53.198025+00
| 2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 |
2014-12-15 00:09:02.10
7445+00 | f       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
 400109 | crawlerperf | 14907 |    16384 | slurp    |                  |
10.250.0.43 |                 |       51462 | 2014-12-14 22:56:20.025004+00
| 2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 |
2014-12-15 00:09:03.87
0266+00 | t       | active | SELECT id,status,checktime FROM jobqueue WHERE
dochash=$1 AND jobid=$2 FOR UPDATE
 400109 | crawlerperf | 18028 |    16384 | slurp    |                  |
10.250.0.43 |                 |       51535 | 2014-12-15 00:03:37.741002+00
| 2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 |
2014-12-15 00:13:12.25
4647+00 | t       | active | SELECT id,status,checktime FROM jobqueue WHERE
dochash=$1 AND jobid=$2 FOR UPDATE
 400109 | crawlerperf | 15976 |    16384 | slurp    |                  |
10.250.0.43 |                 |       51490 | 2014-12-14 23:18:51.369753+00
|                               | 2014-12-15 00:16:55.490487+00 |
2014-12-15 00:16:55.49
0511+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
 400109 | crawlerperf | 18175 |       10 | postgres |
|             |                 |             | 2014-12-15
00:07:55.204579+00 | 2014-12-15 00:07:55.403813+00 | 2014-12-15
00:07:55.403813+00 | 2014-12-15 00:07:55.40
3813+00 | f       | active | autovacuum: VACUUM public.jobqueue
 400109 | crawlerperf | 17632 |       10 | postgres | psql
|             |                 |          -1 | 2014-12-14
23:52:55.506248+00 | 2014-12-15 00:16:56.690037+00 | 2014-12-15
00:16:56.690037+00 | 2014-12-15 00:16:56.69
0037+00 | f       | active | SELECT * FROM pg_stat_activity WHERE datname =
'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr, query_start;
(13 rows)


Cheers,
Aeham

Re: Scaling in MCF

Posted by Karl Wright <da...@gmail.com>.
bq. Just for my own understanding, what is it in manifold that would enforce
the above assertion?

Document priorities are assigned at the time documents are added to the
queue.  Documents are processed in the order that their priorities are
assigned.  So if you start adding new documents from a job just started,
they will be added with document priorities that place them after all other
documents that have currently been prioritized.

Karl


On Mon, Dec 15, 2014 at 9:08 AM, Aeham Abushwashi <
aeham.abushwashi@exonar.com> wrote:
>
> Hi Karl,
>
> I think this approach would work very well for us because we don't
> explicitly create document bins. The only entries in the docbins table
> correspond 1-to-1 to the individual jobs.
> I'll apply the patch and test.
>
> >> This will mean that jobs with bins that overlap other jobs will not make
> any progress until the documents from those other jobs are processed
>
> Just for my own understanding, what is it in manifold that would enforce
> the above assertion?
>
> Thank you,
> Aeham
>

Re: Scaling in MCF

Posted by Aeham Abushwashi <ae...@exonar.com>.
Hi Karl,

I think this approach would work very well for us because we don't
explicitly create document bins. The only entries in the docbins table
correspond 1-to-1 to the individual jobs.
I'll apply the patch and test.

>> This will mean that jobs with bins that overlap other jobs will not make
any progress until the documents from those other jobs are processed

Just for my own understanding, what is it in manifold that would enforce
the above assertion?

Thank you,
Aeham

Re: Scaling in MCF

Posted by Karl Wright <da...@gmail.com>.
I attached a patch which turns off reprioritization for job starts and job
resumes.  This will mean that jobs with bins that overlap other jobs will
not make any progress until the documents from those other jobs are
processed, but that may be acceptable to you.

Karl


On Mon, Dec 15, 2014 at 7:22 AM, Karl Wright <da...@gmail.com> wrote:
>
> Hi Aeham,
>
> I've created ticket CONNECTORS-1122 to track any ideas that people have to
> make job start be faster under the new document reprioritization situation.
>
> Karl
>
>
> On Mon, Dec 15, 2014 at 6:53 AM, Karl Wright <da...@gmail.com> wrote:
>>
>> Hi Aeham,
>>
>> Unless MCF were to know in advance that each document prioritization bin
>> was confined to a single job, it is not possible to mark only part of the
>> documents for reprioritization at this time.  But prioritization bins go
>> cross-job, and that's where the problem lies.  Adding or removing active
>> documents requires reprioritization by definition, unless there would be a
>> way to quickly determine which document bins were in fact represented in
>> any given job.  That's a relatively slow process, but we could try that at
>> some point if you like.
>>
>> Karl
>>
>>
>> On Mon, Dec 15, 2014 at 5:29 AM, Aeham Abushwashi <
>> aeham.abushwashi@exonar.com> wrote:
>>>
>>> Below is a cutdown version of the pg_stat_activity dump...
>>>
>>> Could the the scope of the docpriority update be limited somehow (based
>>> on
>>> needpriority?) to only those rows that need it? If a bunch of jobs are
>>> started back to back (which I would say is a reasonably common use case
>>> especially for continuous crawls), there will be a huge amount of
>>> repeated,
>>> and therefore redundant, docpriority updates. Granted that the choice of
>>> field for limiting the update scope may require an additional sql index.
>>>
>>>
>>>           xact_start           |          query_start          |
>>> state_change          | waiting | state
>>> |                                                         query
>>>
>>> -------------------------------+-------------------------------+-------------------------------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
>>>  2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  |
>>> 2014-12-14
>>> 23:51:29.44226+00  | t       | active | UPDATE jobqueue SET
>>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>>  2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 |
>>> 2014-12-15
>>> 00:09:15.161376+00 | t       | active | UPDATE jobqueue SET
>>> status=$1,processid=$2 WHERE id=$3
>>>                                | 2014-12-15 00:16:51.936374+00 |
>>> 2014-12-15
>>> 00:16:51.936374+00 | f       | idle   | SELECT id FROM jobs WHERE
>>> status=$1
>>>                                | 2014-12-15 00:16:52.176358+00 |
>>> 2014-12-15
>>> 00:16:52.176402+00 | f       | idle   | SELECT * FROM agents
>>>  2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 |
>>> 2014-12-15
>>> 00:03:43.593023+00 | t       | active | UPDATE jobqueue SET
>>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>>                                | 2014-12-15 00:16:48.157249+00 |
>>> 2014-12-15
>>> 00:16:48.157249+00 | f       | idle   | SELECT * FROM agents
>>>  2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 |
>>> 2014-12-15
>>> 00:16:54.550777+00 | f       | active | SELECT id,dochash,docid,jobid
>>> FROM
>>> jobqueue WHERE needpriority=$1 LIMIT 1000
>>>  2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 |
>>> 2014-12-15
>>> 00:09:02.107445+00 | f       | active | UPDATE jobqueue SET
>>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>>  2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 |
>>> 2014-12-15
>>> 00:09:03.870266+00 | t       | active | SELECT id,status,checktime FROM
>>> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>>>  2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 |
>>> 2014-12-15
>>> 00:13:12.254647+00 | t       | active | SELECT id,status,checktime FROM
>>> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>>>                                | 2014-12-15 00:16:55.490487+00 |
>>> 2014-12-15
>>> 00:16:55.490511+00 | f       | idle   | SELECT id FROM jobs WHERE
>>> status=$1
>>>  2014-12-15 00:07:55.403813+00 | 2014-12-15 00:07:55.403813+00 |
>>> 2014-12-15
>>> 00:07:55.403813+00 | f       | active | autovacuum: VACUUM
>>> public.jobqueue
>>>  2014-12-15 00:16:56.690037+00 | 2014-12-15 00:16:56.690037+00 |
>>> 2014-12-15
>>> 00:16:56.690037+00 | f       | active | SELECT * FROM pg_stat_activity
>>> WHERE datname = 'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr,
>>> query_start;
>>>
>>

Re: Scaling in MCF

Posted by Karl Wright <da...@gmail.com>.
Hi Aeham,

I've created ticket CONNECTORS-1122 to track any ideas that people have to
make job start be faster under the new document reprioritization situation.

Karl


On Mon, Dec 15, 2014 at 6:53 AM, Karl Wright <da...@gmail.com> wrote:
>
> Hi Aeham,
>
> Unless MCF were to know in advance that each document prioritization bin
> was confined to a single job, it is not possible to mark only part of the
> documents for reprioritization at this time.  But prioritization bins go
> cross-job, and that's where the problem lies.  Adding or removing active
> documents requires reprioritization by definition, unless there would be a
> way to quickly determine which document bins were in fact represented in
> any given job.  That's a relatively slow process, but we could try that at
> some point if you like.
>
> Karl
>
>
> On Mon, Dec 15, 2014 at 5:29 AM, Aeham Abushwashi <
> aeham.abushwashi@exonar.com> wrote:
>>
>> Below is a cutdown version of the pg_stat_activity dump...
>>
>> Could the the scope of the docpriority update be limited somehow (based on
>> needpriority?) to only those rows that need it? If a bunch of jobs are
>> started back to back (which I would say is a reasonably common use case
>> especially for continuous crawls), there will be a huge amount of
>> repeated,
>> and therefore redundant, docpriority updates. Granted that the choice of
>> field for limiting the update scope may require an additional sql index.
>>
>>
>>           xact_start           |          query_start          |
>> state_change          | waiting | state
>> |                                                         query
>>
>> -------------------------------+-------------------------------+-------------------------------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
>>  2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  |
>> 2014-12-14
>> 23:51:29.44226+00  | t       | active | UPDATE jobqueue SET
>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>  2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 |
>> 2014-12-15
>> 00:09:15.161376+00 | t       | active | UPDATE jobqueue SET
>> status=$1,processid=$2 WHERE id=$3
>>                                | 2014-12-15 00:16:51.936374+00 |
>> 2014-12-15
>> 00:16:51.936374+00 | f       | idle   | SELECT id FROM jobs WHERE
>> status=$1
>>                                | 2014-12-15 00:16:52.176358+00 |
>> 2014-12-15
>> 00:16:52.176402+00 | f       | idle   | SELECT * FROM agents
>>  2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 |
>> 2014-12-15
>> 00:03:43.593023+00 | t       | active | UPDATE jobqueue SET
>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>                                | 2014-12-15 00:16:48.157249+00 |
>> 2014-12-15
>> 00:16:48.157249+00 | f       | idle   | SELECT * FROM agents
>>  2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 |
>> 2014-12-15
>> 00:16:54.550777+00 | f       | active | SELECT id,dochash,docid,jobid FROM
>> jobqueue WHERE needpriority=$1 LIMIT 1000
>>  2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 |
>> 2014-12-15
>> 00:09:02.107445+00 | f       | active | UPDATE jobqueue SET
>> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>>  2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 |
>> 2014-12-15
>> 00:09:03.870266+00 | t       | active | SELECT id,status,checktime FROM
>> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>>  2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 |
>> 2014-12-15
>> 00:13:12.254647+00 | t       | active | SELECT id,status,checktime FROM
>> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>>                                | 2014-12-15 00:16:55.490487+00 |
>> 2014-12-15
>> 00:16:55.490511+00 | f       | idle   | SELECT id FROM jobs WHERE
>> status=$1
>>  2014-12-15 00:07:55.403813+00 | 2014-12-15 00:07:55.403813+00 |
>> 2014-12-15
>> 00:07:55.403813+00 | f       | active | autovacuum: VACUUM public.jobqueue
>>  2014-12-15 00:16:56.690037+00 | 2014-12-15 00:16:56.690037+00 |
>> 2014-12-15
>> 00:16:56.690037+00 | f       | active | SELECT * FROM pg_stat_activity
>> WHERE datname = 'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr,
>> query_start;
>>
>

Re: Scaling in MCF

Posted by Karl Wright <da...@gmail.com>.
Hi Aeham,

Unless MCF were to know in advance that each document prioritization bin
was confined to a single job, it is not possible to mark only part of the
documents for reprioritization at this time.  But prioritization bins go
cross-job, and that's where the problem lies.  Adding or removing active
documents requires reprioritization by definition, unless there would be a
way to quickly determine which document bins were in fact represented in
any given job.  That's a relatively slow process, but we could try that at
some point if you like.

Karl


On Mon, Dec 15, 2014 at 5:29 AM, Aeham Abushwashi <
aeham.abushwashi@exonar.com> wrote:
>
> Below is a cutdown version of the pg_stat_activity dump...
>
> Could the the scope of the docpriority update be limited somehow (based on
> needpriority?) to only those rows that need it? If a bunch of jobs are
> started back to back (which I would say is a reasonably common use case
> especially for continuous crawls), there will be a huge amount of repeated,
> and therefore redundant, docpriority updates. Granted that the choice of
> field for limiting the update scope may require an additional sql index.
>
>
>           xact_start           |          query_start          |
> state_change          | waiting | state
> |                                                         query
>
> -------------------------------+-------------------------------+-------------------------------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
>  2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  | 2014-12-14
> 23:51:29.44226+00  | t       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>  2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 | 2014-12-15
> 00:09:15.161376+00 | t       | active | UPDATE jobqueue SET
> status=$1,processid=$2 WHERE id=$3
>                                | 2014-12-15 00:16:51.936374+00 | 2014-12-15
> 00:16:51.936374+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
>                                | 2014-12-15 00:16:52.176358+00 | 2014-12-15
> 00:16:52.176402+00 | f       | idle   | SELECT * FROM agents
>  2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 | 2014-12-15
> 00:03:43.593023+00 | t       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>                                | 2014-12-15 00:16:48.157249+00 | 2014-12-15
> 00:16:48.157249+00 | f       | idle   | SELECT * FROM agents
>  2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 | 2014-12-15
> 00:16:54.550777+00 | f       | active | SELECT id,dochash,docid,jobid FROM
> jobqueue WHERE needpriority=$1 LIMIT 1000
>  2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 | 2014-12-15
> 00:09:02.107445+00 | f       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>  2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 | 2014-12-15
> 00:09:03.870266+00 | t       | active | SELECT id,status,checktime FROM
> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>  2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 | 2014-12-15
> 00:13:12.254647+00 | t       | active | SELECT id,status,checktime FROM
> jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
>                                | 2014-12-15 00:16:55.490487+00 | 2014-12-15
> 00:16:55.490511+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
>  2014-12-15 00:07:55.403813+00 | 2014-12-15 00:07:55.403813+00 | 2014-12-15
> 00:07:55.403813+00 | f       | active | autovacuum: VACUUM public.jobqueue
>  2014-12-15 00:16:56.690037+00 | 2014-12-15 00:16:56.690037+00 | 2014-12-15
> 00:16:56.690037+00 | f       | active | SELECT * FROM pg_stat_activity
> WHERE datname = 'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr,
> query_start;
>

Re: Scaling in MCF

Posted by Aeham Abushwashi <ae...@exonar.com>.
Below is a cutdown version of the pg_stat_activity dump...

Could the the scope of the docpriority update be limited somehow (based on
needpriority?) to only those rows that need it? If a bunch of jobs are
started back to back (which I would say is a reasonably common use case
especially for continuous crawls), there will be a huge amount of repeated,
and therefore redundant, docpriority updates. Granted that the choice of
field for limiting the update scope may require an additional sql index.


          xact_start           |          query_start          |
state_change          | waiting | state
|                                                         query
-------------------------------+-------------------------------+-------------------------------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
 2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  | 2014-12-14
23:51:29.44226+00  | t       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
 2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 | 2014-12-15
00:09:15.161376+00 | t       | active | UPDATE jobqueue SET
status=$1,processid=$2 WHERE id=$3
                               | 2014-12-15 00:16:51.936374+00 | 2014-12-15
00:16:51.936374+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
                               | 2014-12-15 00:16:52.176358+00 | 2014-12-15
00:16:52.176402+00 | f       | idle   | SELECT * FROM agents
 2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 | 2014-12-15
00:03:43.593023+00 | t       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
                               | 2014-12-15 00:16:48.157249+00 | 2014-12-15
00:16:48.157249+00 | f       | idle   | SELECT * FROM agents
 2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 | 2014-12-15
00:16:54.550777+00 | f       | active | SELECT id,dochash,docid,jobid FROM
jobqueue WHERE needpriority=$1 LIMIT 1000
 2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 | 2014-12-15
00:09:02.107445+00 | f       | active | UPDATE jobqueue SET
docpriority=$1,needpriority=$2 WHERE docpriority<$3
 2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 | 2014-12-15
00:09:03.870266+00 | t       | active | SELECT id,status,checktime FROM
jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
 2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 | 2014-12-15
00:13:12.254647+00 | t       | active | SELECT id,status,checktime FROM
jobqueue WHERE dochash=$1 AND jobid=$2 FOR UPDATE
                               | 2014-12-15 00:16:55.490487+00 | 2014-12-15
00:16:55.490511+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
 2014-12-15 00:07:55.403813+00 | 2014-12-15 00:07:55.403813+00 | 2014-12-15
00:07:55.403813+00 | f       | active | autovacuum: VACUUM public.jobqueue
 2014-12-15 00:16:56.690037+00 | 2014-12-15 00:16:56.690037+00 | 2014-12-15
00:16:56.690037+00 | f       | active | SELECT * FROM pg_stat_activity
WHERE datname = 'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr,
query_start;

Re: Scaling in MCF

Posted by Karl Wright <da...@gmail.com>.
Hi Aeham,

FWIW, it's pretty difficult reading the dump you provided.  If you could
include only the pertinent columns, that would help a lot.

>>>>>>
My guess is that as the stuffer thread picks up items and updates their
status and process id, it can get blocked (indirectly?) by the
repriotisation query issued when a job is started. This causes the stuffer
thread to stall and subsequently no documents are processed by any node in
the cluster.
<<<<<<

Starting a job now must mark all active jobqueue records as needing
document priorities.  This necessarily takes quite some time, independently
of actually computing the document priorities, which happens later.  Since
the query that signals that prioritization is needed is not done in chunks,
nothing else gets past it either.

I knew this was likely to happen when I reorganized the code around
document prioritization based on earlier conversations we've had.  If you
recall, I expressed concern that any activity that requires large numbers
of jobqueue records to be written would in fact eventually be the factor
that limits MCF's ability to scale.  But I have found no solution to the
problem, since document prioritization must be done with all active
documents in mind.

Thanks,
Karl




On Sun, Dec 14, 2014 at 7:40 PM, Aeham Abushwashi <
aeham.abushwashi@exonar.com> wrote:
>
> Hi Karl,
>
> I have some analysis to share wrt job starting performance...
>
> After starting a handful of new jobs, my 3-node mcf cluster (dev_1x and
> already populated with ~10M jobqueue records) appeared to have stalled. The
> stuffer threads on two nodes were waiting on the stuffer lock. The stuffer
> thread on the third node was blocked on the execution of the sql query in
> JobQueue#updateActiveRecord.
>
> My guess is that as the stuffer thread picks up items and updates their
> status and process id, it can get blocked (indirectly?) by the
> repriotisation query issued when a job is started. This causes the stuffer
> thread to stall and subsequently no documents are processed by any node in
> the cluster.
>
> Below is a dump of the pg_stat_activity table. Note the values of the
> 'waiting' column (true/false). The second row corresponds to the query
> invoked by JobQueue#updateActiveRecord
>
>  datid  |   datname   |  pid  | usesysid | usename  | application_name |
> client_addr | client_hostname | client_port |         backend_start
> |          xact_start           |          query_start          |
> state_change
>         | waiting | state
> |                                                         query
>
> --------+-------------+-------+----------+----------+------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-----------------------
>
> --------+---------+--------+-----------------------------------------------------------------------------------------------------------------------
>  400109 | crawlerperf | 16001 |    16384 | slurp    |                  |
> 10.250.0.23 |                 |       52790 | 2014-12-14 23:19:25.909125+00
> | 2014-12-14 23:51:29.440873+00 | 2014-12-14 23:51:29.44226+00  |
> 2014-12-14 23:51:29.44
> 226+00  | t       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>  400109 | crawlerperf | 17020 |    16384 | slurp    |                  |
> 10.250.0.23 |                 |       52813 | 2014-12-14 23:44:31.286417+00
> | 2014-12-15 00:09:02.179227+00 | 2014-12-15 00:09:15.161376+00 |
> 2014-12-15 00:09:15.16
> 1376+00 | t       | active | UPDATE jobqueue SET status=$1,processid=$2
> WHERE id=$3
>  400109 | crawlerperf | 16744 |    16384 | slurp    |                  |
> 10.250.0.23 |                 |       52807 | 2014-12-14 23:37:22.181826+00
> |                               | 2014-12-15 00:16:51.936374+00 |
> 2014-12-15 00:16:51.93
> 6374+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
>  400109 | crawlerperf | 17022 |    16384 | slurp    |                  |
> 10.250.0.23 |                 |       52815 | 2014-12-14 23:44:31.402114+00
> |                               | 2014-12-15 00:16:52.176358+00 |
> 2014-12-15 00:16:52.17
> 6402+00 | f       | idle   | SELECT * FROM agents
>  400109 | crawlerperf | 14258 |    16384 | slurp    |                  |
> 10.250.0.33 |                 |       55885 | 2014-12-14 22:43:56.316824+00
> | 2014-12-15 00:03:43.584173+00 | 2014-12-15 00:03:43.593023+00 |
> 2014-12-15 00:03:43.59
> 3023+00 | t       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>  400109 | crawlerperf | 13832 |    16384 | slurp    |                  |
> 10.250.0.33 |                 |       55882 | 2014-12-14 22:30:47.752513+00
> |                               | 2014-12-15 00:16:48.157249+00 |
> 2014-12-15 00:16:48.15
> 7249+00 | f       | idle   | SELECT * FROM agents
>  400109 | crawlerperf | 17745 |    16384 | slurp    |                  |
> 10.250.0.33 |                 |       55901 | 2014-12-14 23:56:01.490378+00
> | 2014-12-15 00:16:54.550487+00 | 2014-12-15 00:16:54.550776+00 |
> 2014-12-15 00:16:54.55
> 0777+00 | f       | active | SELECT id,dochash,docid,jobid FROM jobqueue
> WHERE needpriority=$1 LIMIT 1000
>  400109 | crawlerperf | 16992 |    16384 | slurp    |                  |
> 10.250.0.43 |                 |       51521 | 2014-12-14 23:43:53.198025+00
> | 2014-12-15 00:09:02.097583+00 | 2014-12-15 00:09:02.107445+00 |
> 2014-12-15 00:09:02.10
> 7445+00 | f       | active | UPDATE jobqueue SET
> docpriority=$1,needpriority=$2 WHERE docpriority<$3
>  400109 | crawlerperf | 14907 |    16384 | slurp    |                  |
> 10.250.0.43 |                 |       51462 | 2014-12-14 22:56:20.025004+00
> | 2014-12-15 00:09:03.795408+00 | 2014-12-15 00:09:03.870265+00 |
> 2014-12-15 00:09:03.87
> 0266+00 | t       | active | SELECT id,status,checktime FROM jobqueue WHERE
> dochash=$1 AND jobid=$2 FOR UPDATE
>  400109 | crawlerperf | 18028 |    16384 | slurp    |                  |
> 10.250.0.43 |                 |       51535 | 2014-12-15 00:03:37.741002+00
> | 2014-12-15 00:13:12.2401+00   | 2014-12-15 00:13:12.254646+00 |
> 2014-12-15 00:13:12.25
> 4647+00 | t       | active | SELECT id,status,checktime FROM jobqueue WHERE
> dochash=$1 AND jobid=$2 FOR UPDATE
>  400109 | crawlerperf | 15976 |    16384 | slurp    |                  |
> 10.250.0.43 |                 |       51490 | 2014-12-14 23:18:51.369753+00
> |                               | 2014-12-15 00:16:55.490487+00 |
> 2014-12-15 00:16:55.49
> 0511+00 | f       | idle   | SELECT id FROM jobs WHERE status=$1
>  400109 | crawlerperf | 18175 |       10 | postgres |
> |             |                 |             | 2014-12-15
> 00:07:55.204579+00 | 2014-12-15 00:07:55.403813+00 | 2014-12-15
> 00:07:55.403813+00 | 2014-12-15 00:07:55.40
> 3813+00 | f       | active | autovacuum: VACUUM public.jobqueue
>  400109 | crawlerperf | 17632 |       10 | postgres | psql
> |             |                 |          -1 | 2014-12-14
> 23:52:55.506248+00 | 2014-12-15 00:16:56.690037+00 | 2014-12-15
> 00:16:56.690037+00 | 2014-12-15 00:16:56.69
> 0037+00 | f       | active | SELECT * FROM pg_stat_activity WHERE datname =
> 'crawlerperf' AND query <> 'COMMIT' ORDER BY client_addr, query_start;
> (13 rows)
>
>
> Cheers,
> Aeham
>