Skip to content

ci: wait for mongod before initiating the replica set, and initiate again - #799

Open
LeeroyHannigan wants to merge 2 commits into
mainfrom
fix/793-mongo-primary-wait
Open

LeeroyHannigan wants to merge 2 commits into
mainfrom
fix/793-mongo-primary-wait

Conversation

@LeeroyHannigan

Copy link
Copy Markdown
Collaborator

What

  • devtools/catalog_checks.py: a new initiate_replica_set(container, port), which start_mongo now calls. Each poll runs db.hello() and reads only the last line of mongosh's output, which has to be exactly primary, initiated (a configuration, no primary yet) or uninitiated (no setName). rs.initiate is sent after each poll that prints uninitiated, so it goes only to a mongod that answered, and it is sent again after an initiate that returned an error. A member that is not primary after 120 polls, with 1 s between them, is reported with the last poll's output, the last initiate's output and the end of the container's log.
  • devtools/check-mongodb-auth: start_with_auth calls initiate_replica_set in place of its own copy of the ping and primary waits. That copy did not report a member that never became primary; the script went on to createUser and failed there.
  • devtools/catalog_checks_test.py: five tests of initiate_replica_set against a fake mongod.

Why

The ping wait added with the MongoDB catalog checks in e0e1068 (#681) took any mongosh output ending in 1 as an answer. A refused connection prints MongoNetworkError: connect ECONNREFUSED 127.0.0.1:<port>, and every port the MongoDB check scripts use in CI ends in 1 (27041, 27051, 27061, 27071, 27081). The wait ended on the first poll whether or not mongod was listening, the single rs.initiate went to a mongod that refused the connection, nothing sent it again, and the check failed with <container> did not become primary. With no mongod listening, the old check returned True on ports 27071 and 27041 and False on 27072.

The failure appeared on #433 (run 41559159173) and #416 (run 41633014404), and #793 lists #783, #463 and #431.

devtools/run-mongodb-tests is not changed. Its ping wait matches a whole line (grep -q '^1$') on port 27017 inside the container, so this bug does not reach it. It still sends a single rs.initiate.

Fixes #793

Testing done

  • python3 -m unittest discover -s devtools -p '*_test.py' -v: 10 tests pass, 5 of them new. They cover refused connections before and after the initiate, an initiate that takes no effect, a member that is never primary, and a mongod that never answers.
  • Each of four bugs put back in a copy of catalog_checks.py fails at least two of the new tests: the suffix match (3 failures), a single initiate before the first poll (4), an initiate after any poll that is not primary (3), and a report without the last poll's output (2).
  • Against mongo:7 on a development host, with each container removed afterwards:
    • start_mongo on 27091: the poll at 1.2 s printed MongoNetworkError: connect ECONNREFUSED 127.0.0.1:27091, the poll at 2.6 s printed uninitiated, one rs.initiate returned { ok: 1 }, and the member was primary at 4.6 s.
    • After replSetStepDown with force: true on that member, five polls 1 s apart printed initiated.
    • check-mongodb-auth's start_with_auth on 27093 (keyFile): one refused poll, uninitiated, one rs.initiate, primary at 4.3 s, and both users created through the localhost exception by 5.2 s.
  • No Rust code changed; cargo test --workspace and cargo fmt --check were not run.

Checklist

  • I have read CONTRIBUTING.md
  • All tests pass (cargo test --workspace)
  • Code is formatted (cargo fmt --check)

…gain

start_mongo in devtools/catalog_checks.py took any mongosh output ending
in 1 as an answered ping. A refused connection prints "MongoNetworkError:
connect ECONNREFUSED 127.0.0.1:<port>", and every port the five MongoDB
check scripts use in CI (27041, 27051, 27061, 27071, 27081) ends in 1, so
the wait ended on the first poll whether or not mongod was listening. The
one rs.initiate then went to a mongod that was not accepting connections
yet, nothing sent it again, and the check failed with "<container> did not
become primary". check-mongodb-auth had a copy of the same wait, which did
not report a member that never became primary.

Both now call initiate_replica_set, which drops the ping. Each poll runs
db.hello() and reads only the last line of mongosh's output, which has to
be exactly primary, initiated (a configuration, no primary yet) or
uninitiated (no setName). rs.initiate is sent after each poll that prints
uninitiated, so it goes only to a mongod that answered, and it is sent
again after an initiate that returned an error. The 120 polls, with 1 s
between them, equal the old ping and primary waits combined. A member that
is not primary after them is reported with the last poll's output, the
last initiate's output and the end of the container's log.

The unit tests cover refused connections before and after the initiate,
an initiate that takes no effect, and both failure reports. Each of four
bugs put back (the suffix match, a single initiate, an initiate after any
poll that is not primary, a report without the poll's output) fails at
least two of them. Against mongo:7, start_mongo on 27091 and
check-mongodb-auth's keyFile set on 27093 were primary in under 6 s, each
after one refused poll and one rs.initiate.

Fixes #793

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

CI: the MongoDB catalog checks fail with "did not become primary" when the one rs.initiate call does not take effect

1 participant