Comment 6 for bug 1720251

Revision history for this message
José Pekkarinen (koalinux) wrote : Re: new controller machines stay in "adding-vote" for over an hour

Hi,

We hit this with the slight difference of redundant controllers never getting
operative. Juju version is 2.2.6 as stated in the output:

$ juju controllers
Use --refresh flag with this command to see the latest information.

Controller Model User Access Cloud/Region Models Machines HA Version
my_controller* default admin superuser my_region 2 142 1/3 2.2.6

$ juju status -m controller
Model Controller Cloud/Region Version SLA
controller my_controller my_region 2.2.6 unsupported

App Version Status Scale Charm Store Rev OS Notes

Unit Workload Agent Machine Public address Ports Message

Machine State DNS Inst id Series AZ Message
0 started X.X.X.18 8dghdf xenial FC1 Deployed
42 started X.X.X.62 tyqpxr xenial FC2 Deployed
43 started X.X.X.29 d4dx38 xenial FC3 Deployed

$ juju ssh -m controller 42

Lessing the machine log I see:

...
2017-11-24 12:09:28 DEBUG juju.worker.dependency engine.go:504 "state" manifold worker stopped: cannot connect to mongodb: no reachable servers
2017-11-24 12:09:28 ERROR juju.worker.dependency engine.go:551 "state" manifold worker returned unexpected error: cannot connect to mongodb: no reachable servers
2017-11-24 12:09:28 DEBUG juju.worker.dependency engine.go:553 stack trace:
no reachable servers
github.com/juju/juju/state/open.go:527: cannot connect to mongodb
github.com/juju/juju/state/open.go:103:
github.com/juju/juju/worker/state/manifold.go:64:
2017-11-24 12:09:31 DEBUG juju.cmd.jujud machine.go:1632 mongo is already initialized
2017-11-24 12:09:31 INFO juju.state open.go:129 opening state, mongo addresses: ["localhost:37017"]; entity machine-42
2017-11-24 12:09:31 DEBUG juju.state open.go:130 dialing mongo
2017-11-24 12:09:31 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
2017-11-24 12:09:32 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
2017-11-24 12:09:33 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
2017-11-24 12:09:34 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
2017-11-24 12:09:35 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
2017-11-24 12:09:36 DEBUG juju.mongo open.go:173 dialled mongodb server at "127.0.0.1:37017"
...

$ sudo lsof -i | grep LISTEN
sshd 3657 root 3u IPv4 21999 0t0 TCP *:ssh (LISTEN)
mongod 15856 root 6u IPv4 22147 0t0 TCP *:37017 (LISTEN)

On primary node mongo I see the following:

juju:PRIMARY> rs.status()
{
        "set" : "juju",
        "date" : ISODate("2017-11-24T12:12:22.569Z"),
        "myState" : 1,
        "term" : NumberLong(42),
        "heartbeatIntervalMillis" : NumberLong(2000),
        "members" : [
                {
                        "_id" : 1,
                        "name" : "127.0.0.1:37017",
                        "health" : 1,
                        "state" : 1,
                        "stateStr" : "PRIMARY",
                        "uptime" : 2767413,
                        "optime" : {
                                "ts" : Timestamp(1511525542, 279),
                                "t" : NumberLong(42)
                        },
                        "optimeDate" : ISODate("2017-11-24T12:12:22Z"),
                        "electionTime" : Timestamp(1508758130, 1),
                        "electionDate" : ISODate("2017-10-23T11:28:50Z"),
                        "configVersion" : 94205,
                        "self" : true
                }
        ],
        "ok" : 1
}

juju:PRIMARY> rs.config()
{
        "_id" : "juju",
        "version" : 94205,
        "protocolVersion" : NumberLong(1),
        "members" : [
                {
                        "_id" : 1,
                        "host" : "127.0.0.1:37017",
                        "arbiterOnly" : false,
                        "buildIndexes" : true,
                        "hidden" : false,
                        "priority" : 1,
                        "tags" : {
                                "juju-machine-id" : "0"
                        },
                        "slaveDelay" : NumberLong(0),
                        "votes" : 1
                }
        ],
        "settings" : {
                "chainingAllowed" : true,
                "heartbeatIntervalMillis" : 2000,
                "heartbeatTimeoutSecs" : 10,
                "electionTimeoutMillis" : 10000,
                "getLastErrorModes" : {

                },
                "getLastErrorDefaults" : {
                        "w" : 1,
                        "wtimeout" : 0
                },
                "replicaSetId" : ObjectId("58f2d2d4824342d527fee1b2")
        }
}

juju:PRIMARY> db.machines.find({ _id: "27633ebe-aa9d-47f1-8465-f03fcd64a673:42" })
... "novote" : false, "hasvote" : false...
juju:PRIMARY> db.machines.find({ _id: "27633ebe-aa9d-47f1-8465-f03fcd64a673:43" })
... "novote" : false, "hasvote" : false...

So no extra nodes added to the replica set, no vote set for the new controllers.

José.