You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@couchdb.apache.org by GitBox <gi...@apache.org> on 2021/07/05 14:49:02 UTC

[GitHub] [couchdb] konrad-ohms commented on issue #3517: Performance regression on CouchDB v3 while using custom reduce function

konrad-ohms commented on issue #3517:
URL: https://github.com/apache/couchdb/issues/3517#issuecomment-874168606


   Thanks @nickva for investigating the issue.
   I tried to adjust the function from
   ```
   setupDbs() {
       COUCHDB_PORT=${1}
       waitForDb "${COUCHDB_PORT}"
       SYSTEM_DBS=( _users _replicator _global_changes demo )
       for CURRENT_DB in "${SYSTEM_DBS[@]}"
       do
           echo "Creating ${CURRENT_DB}"
           curl -X PUT "http://${COUCHDB_USER}:${COUCHDB_PASSWORD}@127.0.0.1:${COUCHDB_PORT}/${CURRENT_DB}"
       done
   }
   ``` 
   to
   ```
   setupDbs() {
       COUCHDB_PORT=${1}
       waitForDb "${COUCHDB_PORT}"
       SYSTEM_DBS=( _users _replicator _global_changes demo )
       for CURRENT_DB in "${SYSTEM_DBS[@]}"
       do
           echo "Creating ${CURRENT_DB}"
           curl -X PUT "http://${COUCHDB_USER}:${COUCHDB_PASSWORD}@127.0.0.1:${COUCHDB_PORT}/${CURRENT_DB}?q=8"
       done
   }
   ```
   
   Unfortunately that did not solve the performance degradation of CouchDB 3.1.1 compared to v2.3.1. 
   
   I checked that the databases are using the same number of shards:
   
   CouchDB 2:
   ```
   ohmsk:~$ curl -u "xxx:xxx" http://localhost:3002/demo/
   {"db_name":"demo","purge_seq":"0-g1AAAAEzeJzLYWBg4MhgTmHgzcvPy09JdcjLz8gvLskBCjPlsQBJhgYg9f____lZiQx41R2AqLuPW11SApBMqgcqImTWA4hZeNQlKYDMsifCrAUQs_bjVpfIkCSP3zIHkGXxEDVZAMg5YvY","update_seq":"12001-g1AAAAFLeJzLYWBg4MhgTmHgzcvPy09JdcjLz8gvLskBCjMlMiTJ____PyuJgYH1Cw41SQpAMskeqoyNFZcyB5CyeJhpD3EpSwApq4cpO4hDWR4LkGRoAFJAlfPBStfjVboAonQ_WOl-vEoPQJTex-triNIHEKUQtz7JAgDbh2kI","sizes":{"file":11425440,"external":11923785,"active":11287083},"other":{"data_size":11923785},"doc_del_count":0,"doc_count":12001,"disk_size":11425440,"disk_format_version":7,"data_size":11287083,"compact_running":false,"cluster":{"q":8,"n":1,"w":1,"r":1},"instance_start_time":"0"}
   ohmsk:~$ curl -u "xxx:xxx" http://localhost:3003/demo/
   ```
   CouchDB 3:
   ```
   {"db_name":"demo","purge_seq":"0-g1AAAAEzeJzLYWBg4MhgTmHgzcvPy09JdcjLz8gvLskBCjPlsQBJhgdA6j8QZCUy4FV3AKLuPiF1CyDq9hNS1wBRNx-3uqQEIJlUj9dtSQ4gNfH41SiA1NjjVZPIkCQPUZAFAN6AYvY","update_seq":"12001-g1AAAAFLeJzLYWBg4MhgTmHgzcvPy09JdcjLz8gvLskBCjPlsQBJhgdA6j8QZCUxMLDew6v0AETpfbDSg3iVLoAo3Q9W-gKv0gaI0vlgpa9wKE1KAJJJ9TB33sGlzAGkLB6mDKdpCiBl9jBll3AoS2RIkoepuZEFAAsmagc","sizes":{"file":14468808,"external":9785687,"active":11343864},"props":{},"doc_del_count":0,"doc_count":12001,"disk_format_version":8,"compact_running":false,"cluster":{"q":8,"n":1,"w":1,"r":1},"instance_start_time":"0"}
   ```
   
   Both state:
   ```
   "cluster":{"q":8,"n":1,"w":1,"r":1}
   ```
   
   After injecting the data I waited multiple minutes before running the queries:
   ```
   ohmsk:~/Downloads/couchdb$ ./couchdb-test.sh query
   CouchDB performance regression test script
   Assuming that setup is already complete
   ================ Query CouchDB 2.3.1 ================
   {"couchdb":"Welcome","version":"2.3.1","git_sha":"c298091a4","uuid":"5584fb6a7a94ff8ab44bbee93823352d","features":["pluggable-storage-engines","scheduler"],"vendor":{"name":"The Apache Software Foundation"}}
   Query Database views on port 3002
   Round: 1/10
   
   real	0m8.534s
   user	0m0.017s
   sys	0m0.013s
   Round: 2/10
   
   real	0m5.050s
   user	0m0.012s
   sys	0m0.010s
   Round: 3/10
   
   real	0m4.677s
   user	0m0.010s
   sys	0m0.011s
   Round: 4/10
   
   real	0m4.820s
   user	0m0.013s
   sys	0m0.009s
   Round: 5/10
   
   real	0m4.798s
   user	0m0.011s
   sys	0m0.011s
   Round: 6/10
   
   real	0m5.093s
   user	0m0.013s
   sys	0m0.009s
   Round: 7/10
   
   real	0m5.285s
   user	0m0.015s
   sys	0m0.007s
   Round: 8/10
   
   real	0m5.627s
   user	0m0.010s
   sys	0m0.014s
   Round: 9/10
   
   real	0m5.459s
   user	0m0.013s
   sys	0m0.010s
   Round: 10/10
   
   real	0m5.589s
   user	0m0.009s
   sys	0m0.015s
   ================ Query CouchDB 3.1.1 ================
   {"couchdb":"Welcome","version":"3.1.1","git_sha":"ce596c65d","uuid":"6445c39f1422b264fbf7837dbb055bb9","features":["access-ready","partitioned","pluggable-storage-engines","reshard","scheduler"],"vendor":{"name":"The Apache Software Foundation"}}
   Query Database views on port 3003
   Round: 1/10
   
   real	0m53.993s
   user	0m0.014s
   sys	0m0.011s
   Round: 2/10
   
   real	0m53.707s
   user	0m0.016s
   sys	0m0.009s
   Round: 3/10
   
   real	0m56.130s
   user	0m0.011s
   sys	0m0.016s
   Round: 4/10
   
   real	0m56.537s
   user	0m0.012s
   sys	0m0.014s
   Round: 5/10
   
   real	0m55.933s
   user	0m0.012s
   sys	0m0.013s
   Round: 6/10
   
   real	0m52.887s
   user	0m0.013s
   sys	0m0.014s
   Round: 7/10
   
   real	1m1.758s
   user	0m0.012s
   sys	0m0.012s
   Round: 8/10
   
   real	0m52.182s
   user	0m0.010s
   sys	0m0.018s
   Round: 9/10
   
   real	0m53.072s
   user	0m0.011s
   sys	0m0.016s
   Round: 10/10
   
   real	0m53.720s
   user	0m0.014s
   sys	0m0.013s
   ```
   
   I am not sure if the default log level does not indicate the auto-builder and auto-compactor actions, but at least the container logs  are not reflecting such actions:
   
   ```
   $ podman logs -f couchdb3
   ...
   [notice] 2021-07-05T12:34:42.581798Z nonode@nohost <0.19894.3> 14ea633501 127.0.0.1:3003 10.0.2.100 admin POST /demo 201 ok 19
   [notice] 2021-07-05T12:34:42.618414Z nonode@nohost <0.19902.3> 96877188fc 127.0.0.1:3003 10.0.2.100 admin POST /demo 201 ok 22
   [notice] 2021-07-05T12:34:42.650066Z nonode@nohost <0.19910.3> c2fe735612 127.0.0.1:3003 10.0.2.100 admin POST /demo 201 ok 20
   [info] 2021-07-05T12:35:10.329291Z nonode@nohost <0.3652.0> -------- Starting index update for db: shards/40000000-5fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:11.749276Z nonode@nohost <0.3652.0> -------- Index update finished for db: shards/40000000-5fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:11.936249Z nonode@nohost <0.3778.0> -------- Starting index update for db: shards/00000000-1fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:13.008010Z nonode@nohost <0.3778.0> -------- Index update finished for db: shards/00000000-1fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:13.291704Z nonode@nohost <0.3817.0> -------- Starting index update for db: shards/e0000000-ffffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:14.564826Z nonode@nohost <0.3817.0> -------- Index update finished for db: shards/e0000000-ffffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:15.314002Z nonode@nohost <0.3907.0> -------- Starting index update for db: shards/20000000-3fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:15.373015Z nonode@nohost <0.3975.0> -------- Starting index update for db: shards/60000000-7fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:15.510076Z nonode@nohost <0.3621.0> -------- Starting index update for db: shards/c0000000-dfffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:16.010943Z nonode@nohost <0.4169.0> -------- Starting index update for db: shards/a0000000-bfffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:16.654203Z nonode@nohost <0.3975.0> -------- Index update finished for db: shards/60000000-7fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:16.677526Z nonode@nohost <0.3907.0> -------- Index update finished for db: shards/20000000-3fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:16.788062Z nonode@nohost <0.3621.0> -------- Index update finished for db: shards/c0000000-dfffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:17.306988Z nonode@nohost <0.4169.0> -------- Index update finished for db: shards/a0000000-bfffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:18.494925Z nonode@nohost <0.3686.0> -------- Starting index update for db: shards/80000000-9fffffff/demo.1625487748 idx: _design/demo
   [info] 2021-07-05T12:35:19.388880Z nonode@nohost <0.3686.0> -------- Index update finished for db: shards/80000000-9fffffff/demo.1625487748 idx: _design/demo
   [notice] 2021-07-05T14:32:23.887866Z nonode@nohost <0.13346.5> 61a2177aae 127.0.0.1:3003 10.0.2.100 admin GET / 200 ok 9
   [notice] 2021-07-05T14:33:17.881591Z nonode@nohost <0.13347.5> 39c531c67e 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 53986
   [notice] 2021-07-05T14:34:11.588538Z nonode@nohost <0.13889.5> d3cc5e0fa8 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 53700
   [notice] 2021-07-05T14:35:07.718592Z nonode@nohost <0.14346.5> 05b6354796 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 56122
   [notice] 2021-07-05T14:36:04.255503Z nonode@nohost <0.14842.5> 1535baf654 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 56529
   [notice] 2021-07-05T14:37:00.187963Z nonode@nohost <0.15334.5> 00a9c90ecf 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 55926
   [notice] 2021-07-05T14:37:53.074959Z nonode@nohost <0.15818.5> e48cbf750a 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 52880
   [notice] 2021-07-05T14:38:54.833050Z nonode@nohost <0.16272.5> 07b2646c16 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 61751
   [notice] 2021-07-05T14:39:47.015319Z nonode@nohost <0.16808.5> a26c18d19d 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 52175
   [notice] 2021-07-05T14:40:40.086929Z nonode@nohost <0.17255.5> 5267817a12 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 53065
   [notice] 2021-07-05T14:41:33.807566Z nonode@nohost <0.17723.5> 21e5c4941c 127.0.0.1:3003 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 53713
   ```
   
   Compared to couchdb2:
   ```
   $ podman logs couchdb2
   ...
   [notice] 2021-07-05T12:27:09.139663Z nonode@nohost <0.23495.2> 714b3e7a37 127.0.0.1:3002 10.0.2.100 admin POST /demo 201 ok 30
   [notice] 2021-07-05T12:27:09.165180Z nonode@nohost <0.23502.2> 9a12b27d94 127.0.0.1:3002 10.0.2.100 admin POST /demo 201 ok 18
   [info] 2021-07-05T13:22:11.293974Z nonode@nohost <0.12126.4> -------- Starting compaction for db "shards/20000000-3fffffff/demo.1625487744" at 1541
   [info] 2021-07-05T13:22:32.858211Z nonode@nohost <0.12139.4> -------- Starting compaction for db "shards/00000000-1fffffff/demo.1625487744" at 1524
   [info] 2021-07-05T13:22:54.395354Z nonode@nohost <0.12142.4> -------- Starting compaction for db "shards/40000000-5fffffff/demo.1625487744" at 1505
   [info] 2021-07-05T13:23:15.835989Z nonode@nohost <0.12145.4> -------- Starting compaction for db "shards/60000000-7fffffff/demo.1625487744" at 1473
   [info] 2021-07-05T13:23:37.277484Z nonode@nohost <0.12151.4> -------- Starting compaction for db "shards/a0000000-bfffffff/demo.1625487744" at 1471
   [info] 2021-07-05T13:23:58.739812Z nonode@nohost <0.12157.4> -------- Starting compaction for db "shards/e0000000-ffffffff/demo.1625487744" at 1508
   [info] 2021-07-05T13:24:20.179296Z nonode@nohost <0.12148.4> -------- Starting compaction for db "shards/80000000-9fffffff/demo.1625487744" at 1455
   [info] 2021-07-05T13:24:41.714250Z nonode@nohost <0.12154.4> -------- Starting compaction for db "shards/c0000000-dfffffff/demo.1625487744" at 1524
   [info] 2021-07-05T13:24:54.231782Z nonode@nohost <0.12450.4> -------- Starting compaction for db "shards/c0000000-dfffffff/_global_changes.1625487744" at 554
   [notice] 2021-07-05T14:31:28.936974Z nonode@nohost <0.15912.6> 312602f8c0 127.0.0.1:3002 10.0.2.100 admin GET / 200 ok 2
   [info] 2021-07-05T14:31:28.989213Z nonode@nohost <0.15983.6> -------- Starting index update for db: shards/00000000-1fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.989257Z nonode@nohost <0.15984.6> -------- Starting index update for db: shards/20000000-3fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.990506Z nonode@nohost <0.16010.6> -------- Starting index update for db: shards/40000000-5fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.990507Z nonode@nohost <0.16011.6> -------- Starting index update for db: shards/a0000000-bfffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.990573Z nonode@nohost <0.16012.6> -------- Starting index update for db: shards/60000000-7fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.990650Z nonode@nohost <0.16016.6> -------- Starting index update for db: shards/80000000-9fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.990715Z nonode@nohost <0.16020.6> -------- Starting index update for db: shards/c0000000-dfffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:28.991237Z nonode@nohost <0.16025.6> -------- Starting index update for db: shards/e0000000-ffffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.578442Z nonode@nohost <0.16012.6> -------- Index update finished for db: shards/60000000-7fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.592533Z nonode@nohost <0.16025.6> -------- Index update finished for db: shards/e0000000-ffffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.624614Z nonode@nohost <0.16011.6> -------- Index update finished for db: shards/a0000000-bfffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.630679Z nonode@nohost <0.16010.6> -------- Index update finished for db: shards/40000000-5fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.641088Z nonode@nohost <0.16016.6> -------- Index update finished for db: shards/80000000-9fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.682452Z nonode@nohost <0.15984.6> -------- Index update finished for db: shards/20000000-3fffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.729299Z nonode@nohost <0.16020.6> -------- Index update finished for db: shards/c0000000-dfffffff/demo.1625487744 idx: _design/demo
   [info] 2021-07-05T14:31:32.746659Z nonode@nohost <0.15983.6> -------- Index update finished for db: shards/00000000-1fffffff/demo.1625487744 idx: _design/demo
   [notice] 2021-07-05T14:31:37.472657Z nonode@nohost <0.15913.6> 3b98ddbf30 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 8516
   [notice] 2021-07-05T14:31:42.522912Z nonode@nohost <0.16231.6> 139c6ac71b 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5042
   [notice] 2021-07-05T14:31:47.199986Z nonode@nohost <0.16315.6> 63625be9aa 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 4671
   [notice] 2021-07-05T14:31:52.020073Z nonode@nohost <0.16417.6> 06140e6373 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 4813
   [notice] 2021-07-05T14:31:56.818616Z nonode@nohost <0.16495.6> 73aef1519b 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 4791
   [notice] 2021-07-05T14:32:01.911785Z nonode@nohost <0.16590.6> e7371ec8db 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5086
   [notice] 2021-07-05T14:32:07.196507Z nonode@nohost <0.16725.6> 19201fdd74 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5278
   [notice] 2021-07-05T14:32:12.823661Z nonode@nohost <0.16833.6> 1cfc7a7f8a 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5618
   [notice] 2021-07-05T14:32:18.282645Z nonode@nohost <0.16924.6> a70a1462dc 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5453
   [notice] 2021-07-05T14:32:23.871410Z nonode@nohost <0.17021.6> 8364bc2506 127.0.0.1:3002 10.0.2.100 admin GET /demo/_design/demo/_view/slow?reduce=true&group=true 200 ok 5581
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@couchdb.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org