'Spring Mongo unable to use primary while performing initial sync
To migrate some production MongoDBs I opted for using replica sets to minimize downtime. While everything is working when running in standalone mode, things fall apart when switching to a RS with the following config
version: "2.2"
services:
mongo:
image: mongo
volumes:
- mongo-data:/data/db
- ./rs-init.sh:/scripts/rs-init.sh:ro
networks:
- appNetwork
ports:
- ${MONGO_PORT}:27017
mem_limit: 1500m
command: --wiredTigerEngineConfigString="cache_size=512M"
entrypoint: [ "/usr/bin/mongod", "--bind_ip_all", "--replSet", "test" ]
restart: always
The rs-init.sh script contains the following:
#!/bin/bash
mongo <<EOF
var config = {
"_id": "test",
"version": 1,
"members": [
{
"_id": 1,
"host": "PRIMARY_NODE_IP:PORT",
"priority": 2
},
{
"_id": 2,
"host": "HIDDEN_NODE_IP:PORT",
"priority": 0,
"hidden": true
}
]
};
rs.initiate(config, { force: true });
EOF
I got it to start syncing. The primary node was in status PRIMARY and the secondary (hidden) node was in STARTUP2. During the initial sync the spring application failed to start with the error:
org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'repositoryMigration' defined in file
[/app/classes/powerbot/server/m7/repositories/RepositoryMigration.class]: Invocation of init method failed; nested exception is
org.springframework.data.mongodb.UncategorizedMongoDbException: Command failed with error 10107 (NotWritablePrimary): 'not
master' on server mongo:27017. The full response is
{
"topologyVersion": {
"processId": {
"$oid": "6258476152adc96e0282f334"
},
"counter": 7
},
"operationTime": {
"$timestamp": {
"t": 1649953064,
"i": 1
}
},
"ok": 0.0,
"errmsg": "not master",
"code": 10107,
"codeName": "NotWritablePrimary",
"$clusterTime": {
"clusterTime": {
"$timestamp": {
"t": 1649953064,
"i": 1
}
},
"signature": {
"hash": {
"$binary": {
"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=",
"subType": "00"
}
},
"keyId": 0
}
}
}
But the primary node indeed was in state PRIMARY and db.isMaster() returned true as well. I noticed three reoccurring log messages that are sent every 10s:
Apr 14, 2022 @ 18:17:39.279 DEBUG Checking status of mongo:27017
Apr 14, 2022 @ 18:17:39.279 DEBUG Updating cluster description to {type=REPLICA_SET, servers=[{address=mongo:27017, type=REPLICA_SET_PRIMARY, roundTripTime=4.2 ms, state=CONNECTED}]
Apr 14, 2022 @ 18:17:49.082 DEBUG Sending command '{"ismaster": 1, "$db": "admin", "$clusterTime": {"clusterTime": {"$timestamp": {"t": 1649953054, "i": 1}}, "signature": {"hash": {"$binary": {"base64": "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "subType": "00"}}, "keyId": 0}}}' with request id 112 to database admin on connection [connectionId{localValue:1, serverValue:17}] to server mongo:27017
But right before spring throws the above exception, there are these odd logs:
Apr 14, 2022 @ 18:18:04.180 DEBUG Updating cluster description to {type=REPLICA_SET, servers=[{address=mongo:27017, type=REPLICA_SET_SECONDARY, roundTripTime=4.0 ms, state=CONNECTED}]
Apr 14, 2022 @ 18:17:54.193 DEBUG Updating cluster description to {type=UNKNOWN, servers=[{address=mongo:27017, type=UNKNOWN, state=CONNECTING}]
Apr 14, 2022 @ 18:17:54.173 DEBUG Updating cluster description to {type=REPLICA_SET, servers=[{address=mongo:27017, type=REPLICA_SET_SECONDARY, roundTripTime=4.0 ms, state=CONNECTED}]
Why is spring updating the cluster description? And why does it not continue to initialize beans while the cluster is not done with the initial sync?
EDIT: added docker-compose and replica set init script
Sources
This article follows the attribution requirements of Stack Overflow and is licensed under CC BY-SA 3.0.
Source: Stack Overflow
| Solution | Source |
|---|
