You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@couchdb.apache.org by Alexey Loshkarev <el...@gmail.com> on 2012/04/11 19:43:59 UTC

replication with 1.2.0 cause excess GET requests for databases

I've updated to 1.2.0 on my production set (2 master-master nodes with
several databases).

I have 2 pull replication of each database (6 databases at each node)
between masters.

After upgrading, i ran replication (via _replication DB).

4 of databases (3 small and 1 about 300k documents) have replicated in
few minutes and two other replicates very slow. Speed is about 100
changes/second (it was about 10-20k changes/second).
I've tried to do custom replication (without _replication db),
continuous or not - the same - very-very slow replication process.
Also, I seeing excess GET-requests on both nodes:

[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.14945.7>] 127.0.0.1 - - GET / 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.399.0>] recording a
checkpoint for `http://node3:5984/exhaust_orders/` -> `exhaust_orders`
at source update_seq 6482987
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
/exhaust_orders/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.32074.6>] recording a
checkpoint for `http://node2:5984/exhaust_events/` -> `exhaust_events`
at source update_seq 4557085
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.137.0>] recording a
checkpoint for `http://node3:5984/exhaust_queues/` -> `exhaust_queues`
at source update_seq 3371674
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
/exhaust_events/ 200
[Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - -
POST /exhaust_orders/_ensure_full_commit 201
...

and so on

so, it's about 10-20 rps on both nodes.
IP 10.0.0.42 - is node2.
Node1 has the same traffic in couchdb.log

exhaust_orders and exhaust_events are last two databases.

What happens with couchdb? Why it requests that databases so fast?


-- 
----------------
Best regards
Alexey Loshkarev
mailto:elf2001@gmail.com

Re: replication with 1.2.0 cause excess GET requests for databases

Posted by Alexey Loshkarev <el...@gmail.com>.
I've realized now, CouchDB ate all my cpu.
I see 4 beam.smp in htop processes eating 100% CPU each (i have 4 cores).
But I have not run any cpu-consuming tasks like view indexing.


2012/4/11 Alexey Loshkarev <el...@gmail.com>:
> I've updated to 1.2.0 on my production set (2 master-master nodes with
> several databases).
>
> I have 2 pull replication of each database (6 databases at each node)
> between masters.
>
> After upgrading, i ran replication (via _replication DB).
>
> 4 of databases (3 small and 1 about 300k documents) have replicated in
> few minutes and two other replicates very slow. Speed is about 100
> changes/second (it was about 10-20k changes/second).
> I've tried to do custom replication (without _replication db),
> continuous or not - the same - very-very slow replication process.
> Also, I seeing excess GET-requests on both nodes:
>
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.14945.7>] 127.0.0.1 - - GET / 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.399.0>] recording a
> checkpoint for `http://node3:5984/exhaust_orders/` -> `exhaust_orders`
> at source update_seq 6482987
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:35 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - - GET
> /exhaust_orders/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.32074.6>] recording a
> checkpoint for `http://node2:5984/exhaust_events/` -> `exhaust_events`
> at source update_seq 4557085
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.137.0>] recording a
> checkpoint for `http://node3:5984/exhaust_queues/` -> `exhaust_queues`
> at source update_seq 3371674
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.31528.6>] 10.0.0.42 - - GET
> /exhaust_events/ 200
> [Wed, 11 Apr 2012 17:34:36 GMT] [info] [<0.12727.7>] 10.0.0.42 - -
> POST /exhaust_orders/_ensure_full_commit 201
> ...
>
> and so on
>
> so, it's about 10-20 rps on both nodes.
> IP 10.0.0.42 - is node2.
> Node1 has the same traffic in couchdb.log
>
> exhaust_orders and exhaust_events are last two databases.
>
> What happens with couchdb? Why it requests that databases so fast?
>
>
> --
> ----------------
> Best regards
> Alexey Loshkarev
> mailto:elf2001@gmail.com



-- 
----------------
Best regards
Alexey Loshkarev
mailto:elf2001@gmail.com