Skip to content

mongo Slow query #138

@YuXiaoCoder

Description

@YuXiaoCoder

System information

OS & Version: Linux Docker
go-spacemesh: v1.4.6
explorer-collector v1.6.0
explorer-apiserver: v1.6.0
mongodb: v6.0.14

Overview of the problem

My node sync is very slow, I watched the logs, go-spacemesh keeps up to date sync, but found that explorer-collector writes data to mongodb very slowly, executes a lot of update statements, mongodb has a lot of Slow query logs

Logs

explorer-collector

2024-04-17T12:18:13.177+0800	INFO	00000.defaultLogger	processing layer
2024-04-17T12:18:14.582+0800	INFO	00000.defaultLogger	syncing layer: 59104
2024-04-17T12:18:14.582+0800	INFO	00000.defaultLogger	syncing accounts for layer: 59104
2024-04-17T12:18:14.582+0800	INFO	00000.defaultLogger	updateLayer(59104) -> 59104, 1, 0, 0, 0xd9420a7d398faf6da033b2d29ce55de36764a2b5b8ce524cfb04a353562436a4
2024-04-17T12:18:14.584+0800	INFO	00000.defaultLogger	updateTransactions
2024-04-17T12:18:14.585+0800	INFO	00000.defaultLogger	updateEpoch(14)
2024-04-17T12:18:14.585+0800	INFO	00000.defaultLogger	Update account sm1qqqqqq8wfd9rha6egj2j25twwq6sufkvnvngt6q73wrpm: balance 30233535749002, counter 2
2024-04-17T12:18:14.986+0800	INFO	00000.defaultLogger	OnAccounts
2024-04-17T12:18:15.779+0800	INFO	00000.defaultLogger	syncing rewards for layer: 59104
2024-04-17T12:18:15.781+0800	INFO	00000.defaultLogger	OnReward(layer:{number:59104} total:{value:672483865} layer_reward:{value:672483865} coinbase:{address:"sm1qqqqqqqq893at3jj8x02rrsf99qvhsp0emy2azsd86nkk"} smesher:{id:"Jϡ\xc1\xff\xc4Ov.\xa1\xe5\x86%uU8N\xb5\xa0H@*\xd8\x1c\x8f\x9b\xf6X\xcbͳ|"})
2024-04-17T12:18:15.783+0800	INFO	00000.defaultLogger	OnReward(layer:{number:59104} total:{value:2521814495} layer_reward:{value:2521814495} coinbase:{address:"sm1qqqqqqqq893at3jj8x02rrsf99qvhsp0emy2azsd86nkk"} smesher:{id:"^T@\x9c\xc1\x19\xaf\x8e\x93d\t\xd6)*G6v\xb6mQfz\x0f\x9cܷ\xb5X˪\xba\x97"})
2024-04-17T12:18:15.784+0800	INFO	00000.defaultLogger	Update account sm1qqqqqqqq893at3jj8x02rrsf99qvhsp0emy2azsd86nkk: balance 10955982322893, counter 170

......
A lot of update logs are omitted here

2024-04-17T12:18:16.046+0800	INFO	00000.defaultLogger	Update account sm1qqqqqq8gnn2ms44ujdqe5zcv9a02tz2vzccuf8geny9vt: balance 10231298145695, counter 65
2024-04-17T12:18:16.047+0800	INFO	00000.defaultLogger	OnReward(layer:{number:59104} total:{value:2521814495} layer_reward:{value:2521814495} coinbase:{address:"sm1qqqqqq8wfd9rha6egj2j25twwq6sufkvnvngt6q73wrpm"} smesher:{id:"ș\x1c69\x8b9\xf4,\xbf\xf8\xf2\xd4\xd9\r\xb6b^sh\xc19\x11\xeei\xed\x1b\x90?\x14\x18z"})
2024-04-17T12:18:16.047+0800	INFO	00000.defaultLogger	Update account sm1qqqqqq8wfd9rha6egj2j25twwq6sufkvnvngt6q73wrpm: balance 30233535749002, counter 2
2024-04-17T12:18:16.048+0800	INFO	00000.defaultLogger	updateEpoch(14)
2024-04-17T12:18:16.049+0800	INFO	00000.defaultLogger	Update account sm1qqqqqq8wfd9rha6egj2j25twwq6sufkvnvngt6q73wrpm: balance 30233535749002, counter 2

mongodb

{"t":{"$date":"2024-04-17T04:23:18.694+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn7","msg":"Slow query","attr":{"type":"command","ns":"explorer.$cmd","command":{"update":"accounts","ordered":true,"lsid":{"id":{"$uuid":"4012c7b6-2523-47e7-896d-eb31cbdc31ed"}},"$db":"explorer"},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":17370}},"FeatureCompatibilityVersion":{"acquireCount":{"w":17370}},"ReplicationStateTransition":{"acquireCount":{"w":17370}},"Global":{"acquireCount":{"w":17370}},"Database":{"acquireCount":{"w":17370}},"Collection":{"acquireCount":{"w":17370}},"Mutex":{"acquireCount":{"r":17370}}},"flowControl":{"acquireCount":17370,"timeAcquiringMicros":7665},"storage":{},"remote":"127.0.0.1:54308","protocol":"op_msg","durationMillis":769}}
{"t":{"$date":"2024-04-17T04:23:26.046+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn5","msg":"Slow query","attr":{"type":"command","ns":"explorer.$cmd","command":{"update":"accounts","ordered":true,"lsid":{"id":{"$uuid":"769ccba0-9265-42d9-a8ff-ec61dfe86276"}},"$db":"explorer"},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":17370}},"FeatureCompatibilityVersion":{"acquireCount":{"w":17370}},"ReplicationStateTransition":{"acquireCount":{"w":17370}},"Global":{"acquireCount":{"w":17370}},"Database":{"acquireCount":{"w":17370}},"Collection":{"acquireCount":{"w":17370}},"Mutex":{"acquireCount":{"r":17370}}},"flowControl":{"acquireCount":17370,"timeAcquiringMicros":6991},"storage":{},"remote":"127.0.0.1:57204","protocol":"op_msg","durationMillis":707}}
{"t":{"$date":"2024-04-17T04:23:33.518+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn7","msg":"Slow query","attr":{"type":"command","ns":"explorer.$cmd","command":{"update":"accounts","ordered":true,"lsid":{"id":{"$uuid":"61eb4488-fa6b-4cd6-9c88-b1bee41d3a61"}},"$db":"explorer"},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":17370}},"FeatureCompatibilityVersion":{"acquireCount":{"w":17370}},"ReplicationStateTransition":{"acquireCount":{"w":17370}},"Global":{"acquireCount":{"w":17370}},"Database":{"acquireCount":{"w":17370}},"Collection":{"acquireCount":{"w":17370}},"Mutex":{"acquireCount":{"r":17370}}},"flowControl":{"acquireCount":17370,"timeAcquiringMicros":6399},"storage":{},"remote":"127.0.0.1:54308","protocol":"op_msg","durationMillis":655}}
{"t":{"$date":"2024-04-17T04:23:41.205+00:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn8","msg":"Slow query","attr":{"type":"command","ns":"explorer.$cmd","command":{"update":"accounts","ordered":true,"lsid":{"id":{"$uuid":"4012c7b6-2523-47e7-896d-eb31cbdc31ed"}},"$db":"explorer"},"numYields":0,"reslen":60,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":17371}},"FeatureCompatibilityVersion":{"acquireCount":{"w":17371}},"ReplicationStateTransition":{"acquireCount":{"w":17371}},"Global":{"acquireCount":{"w":17371}},"Database":{"acquireCount":{"w":17371}},"Collection":{"acquireCount":{"w":17371}},"Mutex":{"acquireCount":{"r":17371}}},"flowControl":{"acquireCount":17371,"timeAcquiringMicros":6741},"storage":{},"remote":"127.0.0.1:54310","protocol":"op_msg","durationMillis":692}}

Reproduction Steps

mongodb

/usr/local/bin/docker-entrypoint.sh mongod --dbpath=/data --bind_ip=127.0.0.1 --wiredTigerCacheSizeGB=4

collector

/opt/smhmain/core/explorer-collector --node-public=127.0.0.1:9092 --node-private=127.0.0.1:9093 --mongodb=mong
odb://127.0.0.1:27017 --db=explorer --sqlite=/mnt/smhmain/node/state.sql

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions