search

spacemeshos / explorer-backend

Spacemesh explorer backend designed to provide data for explorer-frontends
GNU General Public License v3.0
6 stars 2 forks source link

mongo Slow query #138

Open YuXiaoCoder opened 5 months ago

YuXiaoCoder commented 5 months ago

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
N0dust commented 5 months ago

Having the same problem...