Slow pagination

[vdbergh]

Looking at old tests is excruciatingly slow. The reason is that Fishtest uses the .skip() method of a cursor. However the mongodb documentation states that this will be slow if the number of documents to be skipped is large.

The skip() method requires the server to scan from the beginning of the input results set before beginning to return results. As the offset increases, skip() will become slower.

See https://docs.mongodb.com/manual/reference/method/cursor.skip/#definition.

One solution would be to equip runs with an indexed count field. This field could then be used for fast pagination.

rundb::new_run() should have a small critical section to atomically create a new counter value.

[ppigazzini]

Little reminder, better to check also the mongodb manual for version 4.2 to avoid issues: https://docs.mongodb.com/v4.2/reference/method/cursor.skip/

After converting "runs" on PROD I will test on DEV the in-place upgrade to mongodb 4.4: https://docs.mongodb.com/manual/release-notes/4.4-upgrade-standalone/

"pgns" collection on PROD is over 60GB, no hard disk space left to use to usual process mongodump -> mongodb upgrade -> mongorestore

Yesterday I raised on PROD the feature compatibility to 4.2, it was still running with the 4.0: https://docs.mongodb.com/manual/release-notes/4.4-upgrade-standalone/#feature-compatibility-version

[vdbergh]

To implement the above solution it seemed most natural to use a transaction to create a new run (I see no other way to do it robustly and fast). However to my surprise I got the following message.

Transaction numbers are only allowed on a replica set member or mongos, full error: {'ok': 0.0, 'errmsg': 'Transaction numbers are only allowed on a replica set member or mongos', 'code': 20, 'codeName': 'IllegalOperation'}

So I followed the instructions here to convert my local mongodb instance to a replica set:

https://docs.mongodb.com/v4.0/tutorial/convert-standalone-to-replica-set/ https://docs.mongodb.com/manual/reference/configuration-options/#replication-options

It seems to be working. My mongod.conf now looks as follows

# mongod.conf

# for documentation of all options, see:
#   http://docs.mongodb.org/manual/reference/configuration-options/

# Where and how to store data.
storage:
  dbPath: /var/lib/mongodb
  journal:
    enabled: true
#  engine:
#  mmapv1:
  wiredTiger:
    engineConfig:
      cacheSizeGB: 1.75

# where to write logging data.
systemLog:
  destination: file
  logAppend: true
  logRotate: reopen
  path: /var/log/mongodb/mongod.log

# network interfaces
net:
  port: 27017
  bindIp: 127.0.0.1

# how the process runs
processManagement:
  timeZoneInfo: /usr/share/zoneinfo

#security:

#operationProfiling:

replication:
   replSetName: rs0

#sharding:

## Enterprise-Only Options:

#auditLog:

#snmp:

Edit: replaced sr0 by rs0.

[ppigazzini]

Already upgraded to mongodb 4.4 in place on DEV:

# time sudo bash upgrade_mongodb_version.sh | tee upgrade_mongodb_version.sh.log
# https://docs.mongodb.com/v5.0/release-notes/5.0-upgrade-standalone/
# https://docs.mongodb.com/v5.0/tutorial/install-mongodb-on-ubuntu/

old_version="4.4"
new_version="5.0"

mongo << EOF
db.adminCommand( { setFeatureCompatibilityVersion: "${old_version}" } )
exit
EOF

echo "stopping cron and fishtest ..."
systemctl stop cron
systemctl stop fishtest@{6543..6544}
sleep 20

echo "uninstalling mongodb ${old_version}..."
systemctl stop mongod
apt purge -y mongodb-org*
apt autoremove -y
rm /etc/apt/sources.list.d/mongodb-org-${old_version}.list

echo "installing mongodb ${new_version} ..."
ubuntu_release=$(lsb_release -c | awk '{print $2}')
wget -qO - https://www.mongodb.org/static/pgp/server-${new_version}.asc | apt-key add -
echo "deb [ arch=amd64,arm64 ] https://repo.mongodb.org/apt/ubuntu ${ubuntu_release}/mongodb-org/${new_version} multiverse" | tee /etc/apt/sources.list.d/mongodb-org-${new_version}.list
apt update
apt install -y mongodb-org

# set the cache size in /etc/mongod.conf
#  wiredTiger:
#    engineConfig:
#      cacheSizeGB: 1.50
cp /etc/mongod.conf mongod.conf.bkp
sed -i 's/^#  wiredTiger:/  wiredTiger:\n    engineConfig:\n      cacheSizeGB: 1.50/' /etc/mongod.conf

# setup logrotate for mongodb
sed -i '/^  logAppend: true/a\  logRotate: reopen' /etc/mongod.conf

echo "starting mongod fishtest and cron ..."
systemctl start mongod
sleep 20
systemctl start fishtest@{6543..6544}
systemctl start cron

[ppigazzini]

Also I enable the free cloud monitoring db.enableFreeMonitoring() https://cloud.mongodb.com/freemonitoring/cluster/V726YST63VGLDMUUVB4GT34WZHIY6L4D

EDIT: ops, missed the last char :)

[vdbergh]

One can also go back from a replica set to a standalone instance

https://medium.com/@cjandsilvap/from-a-replica-set-to-a-standalone-mongodb-79fda2beaaaf

So perhaps worth looking at? It would be quite convenient to be able to use transactions.

[ppigazzini]

Ok. I will try on DEV after moving PROD on 4.4 and, if successful, on 5.0.

[ppigazzini]

BTW I need to check the HD space before and after upgrades.

[ppigazzini]

PROD updated to mongodb 4.4, still using featureCompatibilityVersion 4.2 at the moment.

[vdbergh]

Things seem to be working well. Changing to a replica set seems to involve just two things:

1. Adding

   replication:
   replSetName: rs0

   to /etc/mongod.conf (https://docs.mongodb.com/manual/reference/configuration-options/#replication-options) and restarting mongod.

2. Executing rs.initiate() once in mongosh (https://docs.mongodb.com/manual/reference/method/rs.initiate/#mongodb-method-rs.initiate)

rs.status() gives the status of the procedure.

I don't see any difference with the stand alone instance, except that transactions are now supported (I do not know why they chose to connect transactions to replication).

[ppigazzini]

PROD updated to mongodb 5.0.5, still using featureCompatibilityVersion 4.4 at the moment. I updated the script in the previous post.

I start testing the replica set upgrade on DEV.

[vdbergh]

Hmm the revert to stand alone instructions from here https://medium.com/@cjandsilvap/from-a-replica-set-to-a-standalone-mongodb-79fda2beaaaf do not appear to work.

[vdbergh]

Actually going back is trivial as well. Just comment out

replication:
   replSetName: rs0

from /etc/mongodb , restart, and (optionally) delete the local database.

[ppigazzini]

PROD mongodb 5.0.5 with featureCompatibilityVersion 5.0 Updated the wiki fishtest server setup script.

[vdbergh]

Perhaps you can add the monitoring URL to the side bar.

[ppigazzini]

Icons:

1. https://fontawesome.com/v5.15/icons/chart-bar?style=solid
2. https://fontawesome.com/v5.15/icons/chart-area?style=solid

[dav1312]

Icons:

1. fontawesome.com/v5.15/icons/chart-bar?style=solid
2. fontawesome.com/v5.15/icons/chart-area?style=regular

I was thinking something like this https://fontawesome.com/v5.15/icons/heartbeat?style=solid Since we already use a chart for the progress

[ppigazzini]

Icons:

1. fontawesome.com/v5.15/icons/chart-bar?style=solid
2. fontawesome.com/v5.15/icons/chart-area?style=regular

I was thinking something like this https://fontawesome.com/v5.15/icons/heartbeat?style=solid Since we already use a chart for the progress

Approved! Could you open a PR?

[ppigazzini]

@vdbergh mongodb replica set enabled on PROD. Tested successfully on DEV the switch to standard also dropping the local collection.

[vdbergh]

Maybe something for a future PR. One can get the URL and the state of free monitoring programmatically. In that way DEV could for example show the monitoring on DEV.

The following is from mongosh but it can of course also be done from pymongo.

rs0:PRIMARY> db.getFreeMonitoringStatus()
{
    "state" : "enabled",
    "message" : "To see your monitoring data, navigate to the unique URL below. Anyone you share the URL with will also be able to view this page. You can disable monitoring at any time by running db.disableFreeMonitoring().",
    "url" : "https://cloud.mongodb.com/freemonitoring/cluster/LP4QLL2YOOBX2IRYQN6BURKYHSK7DYVO",
    "userReminder" : "Free Monitoring URL:\nhttps://cloud.mongodb.com/freemonitoring/cluster/LP4QLL2YOOBX2IRYQN6BURKYHSK7DYVO",
    "ok" : 1,
    "$clusterTime" : {
        "clusterTime" : Timestamp(1641301535, 1),
        "signature" : {
            "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
            "keyId" : NumberLong(0)
        }
    },
    "operationTime" : Timestamp(1641301535, 1)
}

[vdbergh]

I figured out how to do it in pymongo

import pprint
import pymongo

if __name__ == '__main__':
    c=pymongo.MongoClient()
    db=c["admin"]
    pprint.pprint(db.command("getFreeMonitoringStatus"))

Output

{'$clusterTime': {'clusterTime': Timestamp(1641303114, 2),
                  'signature': {'hash': b'\x00\x00\x00\x00\x00\x00\x00\x00'
                                        b'\x00\x00\x00\x00\x00\x00\x00\x00'
                                        b'\x00\x00\x00\x00',
                                'keyId': 0}},
 'message': 'To see your monitoring data, navigate to the unique URL below. '
            'Anyone you share the URL with will also be able to view this '
            'page. You can disable monitoring at any time by running '
            'db.disableFreeMonitoring().',
 'ok': 1.0,
 'operationTime': Timestamp(1641303114, 2),
 'state': 'enabled',
 'url': 'https://cloud.mongodb.com/freemonitoring/cluster/LP4QLL2YOOBX2IRYQN6BURKYHSK7DYVO',
 'userReminder': 'Free Monitoring URL:\n'
                 'https://cloud.mongodb.com/freemonitoring/cluster/LP4QLL2YOOBX2IRYQN6BURKYHSK7DYVO'}

[vdbergh]

I must say that is a mystery to me why skipping in a cursor is so slow in fishtest.

If a query is supported by an index, then it means we have to find the nth element in a b-tree. This is a standard operation and it should not be slow for a b-tree with at most ~100000 items.

It is hard to find any documentation on mongodb's internals.

[vdbergh]

The explanation that's usually given is that skipping is slow because mongodb has to read the skipped documents.

But this makes no sense if there is an index covering the queried fields.

[ppigazzini]

I'm commuting now, I'm not able to view the pagination code. Yesterday I read in the mongodb documentation that a cursor is not a python list, indexing and slicing require new queries and so are slow operations.

EDIT_000: here the reference: https://pymongo.readthedocs.io/en/stable/api/pymongo/cursor.html#pymongo.cursor.Cursor.__getitem__

"Warning A Cursor is not a Python list. Each index access or slice requires that a new query be run using skip and limit. Do not iterate the cursor using index accesses. The following example is extremely inefficient and may return surprising results:"

cursor = db.collection.find()
# Warning: This runs a new query for each document.
# Don't do this!
for idx in range(10):
    print(cursor[idx])

[vdbergh]

I am assuming that mongodb indexes use b-trees with recursive counting information, but maybe that's not the case. In that case skip would require scanning the index. That would explain why it is slow.

[vdbergh]

Yes this seems to be the issue. It seems no database permits efficient paging (with jump to middle) of a dynamic table, not even when using indexes. For a read only table one can add a ‘count’ field to the table and use a range query on that.

[vdbergh]

So it seems that this is not fixable without a lot of messy code (essentially introducing our own indexing). Since it is not a serious problem (pagination of recent runs is fast), it is not worth polluting the Fishtest code base for.

[vdbergh]

In the end it turned out that this issue had a much more trivial explanation. Mongodb wasn't using any indexes most of the time #1242 ! It's a miracle that things still worked as well as they did. Solved via #1243