Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Databases/MongoDB - error 500 on creds generation when mongodb replicaset primary step-down #2973

Closed
drakeu opened this issue Jul 5, 2017 · 25 comments · Fixed by #3269 or #3717
Closed
Milestone

Comments

@drakeu
Copy link

drakeu commented Jul 5, 2017

I have following environmnent setup:
3 node mongodb replicaset
3 node vault (v0.7.3) cluster with store on 3 server consul (0.8.3) cluster
Configured databases - mongodb secret backend.
My anonymised connection_url:
connection_url:mongodb://USER:[email protected]:27017,y.y.y.y:27017,z.z.z.z:27017/admin?replicaSet=REPLICASETNAME
Problem:
After configuration it works perfect. But when mongodb steps down primary and select new one I receive following error when I try generate credentials:

 Error reading mongodb/creds/payments: Error making API request.

URL: GET http://x.x.x.x:8200/v1/mongodb/creds/payments
Code: 500. Errors:

* 1 error occurred:

* EOF

I temporary fix situation by running vault step-down. After that vault starts generate credentials.

@jefferai
Copy link
Member

jefferai commented Jul 5, 2017

Do you see this problem using the combined database backend? https://www.vaultproject.io/docs/secrets/databases/mongodb.html

The existing one is deprecated at this point. If this is a setup I'd recommend using that instead.

@jefferai jefferai added this to the 0.7.4 milestone Jul 5, 2017
@drakeu
Copy link
Author

drakeu commented Jul 5, 2017

Yes. I use https://www.vaultproject.io/docs/secrets/databases/mongodb.html beta backend and I observe problem with it, not with deprecated one. Sorry for misleading name of mountpoint. In this ticket this name is fake for public use and it has format RSNAME_mongodb. I currently mount only one combined database backend.

@jefferai
Copy link
Member

jefferai commented Jul 5, 2017

@drakeu when you got that EOF Vault probably printed out a panic into its server log (which goes to stdout). Can you supply Vault's server logs from when that's run?

@drakeu
Copy link
Author

drakeu commented Jul 5, 2017

Logs when I try to release 2 instances of service (java spring with spring cloud vault configuration) which using databases/mongodb backend. In log I have only two entries in this step:

July 5th 2017, 09:14:11.572	2017/07/05 07:14:11.572405 [ERROR] sys: lease revocation failed: lease_id=XXX_mongo/creds/payments/bc91c10b-1c19-3a8f-0996-3c64abaa1d83 error=failed to revoke entry: resp:(*logical.Response)(nil) err:EOF
July 5th 2017, 09:14:13.996	2017/07/05 07:14:13.997640 [ERROR] sys: lease revocation failed: lease_id=XXX_mongo/creds/payments/4d1e45b1-55b1-7fe8-c6b4-31204721eb84 error=failed to revoke entry: resp:(*logical.Response)(nil) err:EOF

After few minutes I decide to try step-down current master:

July 5th 2017, 09:38:32.121	2017/07/05 07:38:32.122704 [WARN ] core: stepping down from active operation to standby
July 5th 2017, 09:38:32.127	2017/07/05 07:38:32.127418 [INFO ] core: pre-seal teardown starting
July 5th 2017, 09:38:32.128	2017/07/05 07:38:32.127535 [INFO ] core: forwarding rpc listeners stopped
July 5th 2017, 09:38:32.128	2017/07/05 07:38:32.127443 [INFO ] core: shutting down forwarding rpc listeners
July 5th 2017, 09:38:32.128	2017/07/05 07:38:32.127436 [INFO ] core: stopping cluster listeners
July 5th 2017, 09:38:32.417	2017/07/05 07:38:32.418210 [INFO ] core: rpc listeners successfully shut down
July 5th 2017, 09:38:32.417	2017/07/05 07:38:32.417797 [WARN ] transport: http2Client.notifyError got notified that the client transport was broken EOF.
July 5th 2017, 09:38:32.421	2017/07/05 07:38:32.419659 [WARN ] grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: Error while dialing dial tcp X.X.X.X:8201: getsockopt: connection refused"; Reconnecting to {X.X.X.X:8201 <nil>}
July 5th 2017, 09:38:32.421	2017/07/05 07:38:32.418242 [INFO ] core: cluster listeners successfully shut down
July 5th 2017, 09:38:32.421	2017/07/05 07:38:32.420441 [WARN ] transport: http2Client.notifyError got notified that the client transport was broken EOF.
July 5th 2017, 09:38:32.423	2017/07/05 07:38:32.421964 [WARN ] grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: Error while dialing dial tcp X.X.X.X:8201: getsockopt: connection refused"; Reconnecting to {X.X.X.X:8201 <nil>}
July 5th 2017, 09:38:32.424	2017/07/05 07:38:32.418552 [INFO ] core: pre-seal teardown complete
July 5th 2017, 09:38:32.424	2017/07/05 07:38:32.418284 [INFO ] rollback: stopping rollback manager
July 5th 2017, 09:38:32.433	2017/07/05 07:38:32.432937 [INFO ] core: acquired lock, enabling active operation
July 5th 2017, 09:38:32.436	2017/07/05 07:38:32.436680 [ERROR] core: failed to acquire lock: error=failed to acquire lock: Unexpected response code: 500 (rpc error: invalid session "b52232cb-1648-d3df-61d4-4d0224c9beb2")
July 5th 2017, 09:38:32.519	2017/07/05 07:38:32.519770 [INFO ] core: post-unseal setup starting
July 5th 2017, 09:38:32.520	2017/07/05 07:38:32.520157 [WARN ] grpc: addrConn.transportMonitor exits due to: context canceled
July 5th 2017, 09:38:32.522	2017/07/05 07:38:32.522130 [INFO ] core: loaded wrapping token key
July 5th 2017, 09:38:32.526	2017/07/05 07:38:32.526579 [INFO ] core: successfully mounted backend: type=generic path=secret/
July 5th 2017, 09:38:32.528	2017/07/05 07:38:32.526949 [INFO ] core: successfully mounted backend: type=system path=sys/
July 5th 2017, 09:38:32.529	2017/07/05 07:38:32.527140 [INFO ] core: successfully mounted backend: type=rabbitmq path=XXX_rabbitmq/
July 5th 2017, 09:38:32.529	2017/07/05 07:38:32.527046 [INFO ] core: successfully mounted backend: type=database path=XXX_mongo/
July 5th 2017, 09:38:32.532	2017/07/05 07:38:32.527201 [INFO ] core: successfully mounted backend: type=consul path=XXX_consul/
July 5th 2017, 09:38:32.546	2017/07/05 07:38:32.527520 [INFO ] rollback: starting rollback manager
July 5th 2017, 09:38:32.546	2017/07/05 07:38:32.527276 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
July 5th 2017, 09:38:32.548	2017/07/05 07:38:32.540222 [INFO ] expiration: restoring leases
July 5th 2017, 09:38:32.571	2017/07/05 07:38:32.571062 [INFO ] expire: leases restored: restored_lease_count=34
July 5th 2017, 09:38:32.575	2017/07/05 07:38:32.575309 [INFO ] core: post-unseal setup complete
July 5th 2017, 09:38:32.576	2017/07/05 07:38:32.575591 [INFO ] core/startClusterListener: starting listener: listener_address=0.0.0.0:8201
July 5th 2017, 09:38:32.578	2017/07/05 07:38:32.575792 [INFO ] core/startClusterListener: serving cluster requests: cluster_listen_address=[::]:8201
July 5th 2017, 09:38:33.421	2017/07/05 07:38:33.422205 [WARN ] grpc: addrConn.resetTransport failed to create client transport: connection error: desc = "transport: Error while dialing dial tcp X.X.X.X:8201: getsockopt: connection refused"; Reconnecting to {X.X.X.X:8201 <nil>}
July 5th 2017, 09:38:33.855	2017/07/05 07:38:33.856121 [WARN ] grpc: addrConn.transportMonitor exits due to: context canceled

After that when I run vault read XXX_mongo/creds/payments from shell - vault generates new username and password.
Then I try to confirm that problem is in mongodb replicaset and I run rs.stepDown() on mongodb primary. After that I run same vault command with result (anonymised mount point):

Error reading XXX_mongo/creds/payments: Error making API request.

URL: GET http://X.X.X.X:8200/v1/XXX_mongo/creds/payments
Code: 500. Errors:

* 1 error occurred:

* EOF

But there is no results in logs for that operation. Next I step-down current vault master and it back to normal.
Maby vault after rs.stepDown() in mongo replicaset it try to connect to old primary and after remounting database backend it refresh which mongo node is primary and works valid?

@jefferai
Copy link
Member

jefferai commented Jul 7, 2017

@drakeu Thanks, that helps clarify whether the EOF is coming from the Mongo connection itself (it is) or from Vault due to a panic (it's not).

Any chance you would be able to build a branch? I could push in a change to try to work around this.

@drakeu
Copy link
Author

drakeu commented Jul 7, 2017

I send you invitation. I'm not golang developer so I can help only in testing.

@jefferai
Copy link
Member

jefferai commented Jul 7, 2017

Hi @drakeu ,

Please try out the mongo-reconnect branch and see if that helps you out. Note that I only made these changes to the Mongo code in the combined database backend.

@drakeu
Copy link
Author

drakeu commented Jul 18, 2017

Hi. It looks that it still not working. What I do:

  1. Clone vault repo and checkout mongo-reconnect branch
  2. Install golang v1.8
  3. In vault directory run make dev (it compiles and gives me binary in bin directory)
  4. Setup simple replicaset using mtools mlaunch --replicaset --nodes 3
  5. Start newly compiled vault in dev mode ./vault server -dev -dev-root-token-id='abc' -log-level=trace
  6. Create mongodb user:
{ user: "vault",
  pwd: "vault.8",
  roles: [
    "root"
  ]
}
  1. Configure database backend in vault:
./vault mount -path abc_mongodb database

./vault write abc_mongodb/config/mongodb \
    plugin_name=mongodb-database-plugin \
    connection_url="mongodb://vault:[email protected]:27017,127.0.0.1:27018,127.0.0.1:27019/admin?replicaSet=replset" \
    allowed_roles="*"

./vault write abc_mongodb/roles/adm \
    db_name=mongodb \
    creation_statements='{ "db": "admin", "roles": [{ "role": "readWrite" }, {"role": "read", "db": "foo"}] }' \
    default_ttl="1h" \
    max_ttl="24h"
  1. First credentials read (user created properly)
./vault read abc_mongodb/creds/adm       
Key            	Value
---            	-----
lease_id       	abc_mongodb/creds/adm/632cc9a0-02c8-b203-f896-3aadf49109d1
lease_duration 	1h0m0s
lease_renewable	true
password       	ddcab806-5b7c-68f1-c76f-33b021fca5e0
username       	v-token-adm-PGSE0T31COC0elGfCZNU-1500417057
  1. In mongodb primary I run rs.stepDown()
  2. Second credentials read
./vault read abc_mongodb/creds/adm
Error reading abc_mongodb/creds/adm: Error making API request.

URL: GET http://127.0.0.1:8200/v1/abc_mongodb/creds/adm
Code: 500. Errors:

* 1 error occurred:

* EOF
  1. Vault logs:
==> Vault server configuration:

                     Cgo: disabled
         Cluster Address: https://127.0.0.1:8201
              Listener 1: tcp (addr: "127.0.0.1:8200", cluster address: "127.0.0.1:8201", tls: "disabled")
               Log Level: trace
                   Mlock: supported: true, enabled: false
        Redirect Address: http://127.0.0.1:8200
                 Storage: inmem
                 Version: Vault v0.7.3
             Version Sha: 58bb94372d00c5bcdf9df556839a61930fa03203

==> WARNING: Dev mode is enabled!

In this mode, Vault is completely in-memory and unsealed.
Vault is configured to only have a single unseal key. The root
token has already been authenticated with the CLI, so you can
immediately begin using the Vault CLI.

The only step you need to take is to set the following
environment variables:

    export VAULT_ADDR='http://127.0.0.1:8200'

The unseal key and root token are reproduced below in case you
want to seal/unseal the Vault or play with authentication.

Unseal Key: MIoJIv2jUChwEcxy+IlZrDHMcTJguRldCGnNh5OkDjg=
Root Token: abc

==> Vault server started! Log data will stream in below:

2017/07/19 00:25:00.754681 [TRACE] physical/cache: creating LRU cache: size=32768
2017/07/19 00:25:00.755135 [TRACE] cluster listener addresses synthesized: cluster_addresses=[127.0.0.1:8201]
2017/07/19 00:25:00.755658 [INFO ] core: security barrier not initialized
2017/07/19 00:25:00.756074 [INFO ] core: security barrier initialized: shares=1 threshold=1
2017/07/19 00:25:00.756476 [TRACE] core: cluster name not found/set, generating new
2017/07/19 00:25:00.756509 [DEBUG] core: cluster name set: name=vault-cluster-a6a100e4
2017/07/19 00:25:00.756533 [TRACE] core: cluster ID not found, generating new
2017/07/19 00:25:00.756560 [DEBUG] core: cluster ID set: id=abbd1781-c493-e9f3-1a41-2fdecc34fe25
2017/07/19 00:25:00.756690 [INFO ] core: post-unseal setup starting
2017/07/19 00:25:00.756701 [TRACE] core: clearing forwarding clients
2017/07/19 00:25:00.756712 [TRACE] core: done clearing forwarding clients
2017/07/19 00:25:00.806983 [INFO ] core: loaded wrapping token key
2017/07/19 00:25:00.812874 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/19 00:25:00.813058 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/19 00:25:00.813370 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/19 00:25:00.813564 [INFO ] rollback: starting rollback manager
2017/07/19 00:25:00.816425 [INFO ] expiration: restoring leases
2017/07/19 00:25:00.816440 [DEBUG] expiration: collecting leases
2017/07/19 00:25:00.816459 [DEBUG] expiration: leases collected: num_existing=0
2017/07/19 00:25:00.820135 [INFO ] core: post-unseal setup complete
2017/07/19 00:25:00.821365 [INFO ] core: root token generated
2017/07/19 00:25:00.821385 [INFO ] core: pre-seal teardown starting
2017/07/19 00:25:00.821409 [INFO ] core: cluster listeners not running
2017/07/19 00:25:00.821444 [INFO ] rollback: stopping rollback manager
2017/07/19 00:25:00.821700 [INFO ] core: pre-seal teardown complete
2017/07/19 00:25:00.821941 [INFO ] core: vault is unsealed
2017/07/19 00:25:00.821994 [INFO ] core: post-unseal setup starting
2017/07/19 00:25:00.822027 [TRACE] core: clearing forwarding clients
2017/07/19 00:25:00.822034 [TRACE] core: done clearing forwarding clients
2017/07/19 00:25:00.822227 [INFO ] core: loaded wrapping token key
2017/07/19 00:25:00.822798 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/19 00:25:00.823138 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/19 00:25:00.823182 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/19 00:25:00.823320 [INFO ] rollback: starting rollback manager
2017/07/19 00:25:00.825256 [INFO ] expiration: restoring leases
2017/07/19 00:25:00.825268 [DEBUG] expiration: collecting leases
2017/07/19 00:25:00.825285 [DEBUG] expiration: leases collected: num_existing=0
2017/07/19 00:25:00.825987 [INFO ] core: post-unseal setup complete
2017/07/19 00:25:29.818604 [INFO ] core: successful mount: path=abc_mongodb/ type=database
2017/07/19 00:25:29.882365 [TRACE] database: operation=Initialize status=started type=mongodb
2017/07/19 00:25:29.936404 [TRACE] database: operation=Initialize status=finished type=mongodb verify=true err=<nil> took=54.03301ms
2017/07/19 00:26:00.824077 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:26:00.824233 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:26:00.824224 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:26:00.824168 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:26:00.824307 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:27:00.823782 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:27:00.823782 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:27:00.823801 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:27:00.823809 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:27:00.823824 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:28:00.823817 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:28:00.823877 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:28:00.823881 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:28:00.823891 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:28:00.823864 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:29:00.823876 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:29:00.823878 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:29:00.823889 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:29:00.823899 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:29:00.823918 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:30:00.823768 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:30:00.823843 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:30:00.823852 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:30:00.823863 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:30:00.823904 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:30:52.546287 [TRACE] database: operation=Initialize status=started type=mongodb
2017/07/19 00:30:52.593858 [TRACE] database: operation=Initialize status=finished type=mongodb verify=true err=<nil> took=47.567367ms
2017/07/19 00:30:52.594041 [TRACE] database: operation=Close status=started type=mongodb
2017/07/19 00:30:52.594242 [TRACE] database: operation=Close status=finished type=mongodb err=<nil> took=201.507µs
2017/07/19 00:30:57.798460 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/19 00:30:57.844777 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=46.318579ms
2017/07/19 00:31:00.823811 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:31:00.823825 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:31:00.823843 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:31:00.823844 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:31:00.823854 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:31:15.524597 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/19 00:31:15.524879 [TRACE] database: operation=CreateUser status=finished type=mongodb err=EOF took=283.855µs
2017/07/19 00:31:50.992638 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/19 00:31:50.992977 [TRACE] database: operation=CreateUser status=finished type=mongodb err=EOF took=339.948µs
2017/07/19 00:32:00.823734 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:32:00.823744 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:32:00.823756 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:32:00.823756 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:32:00.823769 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:33:00.823690 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:33:00.823690 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:33:00.823701 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:33:00.823712 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:33:00.824025 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:34:00.823677 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:34:00.823676 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:34:00.823687 [TRACE] rollback: attempting rollback: path=sys/
2017/07/19 00:34:00.823693 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:34:00.823717 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:35:00.823805 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/19 00:35:00.823822 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/19 00:35:00.823837 [TRACE] rollback: attempting rollback: path=secret/
2017/07/19 00:35:00.823850 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/19 00:35:00.823865 [TRACE] rollback: attempting rollback: path=sys/

@calvn
Copy link
Contributor

calvn commented Jul 18, 2017

It looks like the creation statement is not valid. On the plugin-based backend, the statement takes in a valid JSON that is different from the mongo-specific format.

Edit: Nevermind, that looks like it's a valid format.

@jefferai
Copy link
Member

I just pushed up another change, please try again (and importantly, be sure to again include logs if it doesn't work).

@drakeu
Copy link
Author

drakeu commented Jul 19, 2017

I'm sorry. I have exactly the same situation as previous. I remove repo directory, clone again, checkout to branch (your commit: c8886bd from Tue Jul 18 19:20:10 2017 -0400), rebuild project (make dev) and repeat previous procedure with started replicaset from mtools -> mlaunch:

➜  bin git:(mongo-reconnect) export VAULT_ADDR='http://127.0.0.1:8200'
➜  bin git:(mongo-reconnect) ./vault auth
Token (will be hidden): 
Successfully authenticated! You are now logged in.
token: abc
token_duration: 0
token_policies: [root]
➜  bin git:(mongo-reconnect) ./vault mount -path abc_mongodb database 
Successfully mounted 'database' at 'abc_mongodb'!
➜  bin git:(mongo-reconnect) ./vault write abc_mongodb/config/mongodb \
    plugin_name=mongodb-database-plugin \
    connection_url="mongodb://vault:[email protected]:27017,127.0.0.1:27018,127.0.0.1:27019/admin?replicaSet=replset" \
    allowed_roles="*"

./vault write abc_mongodb/roles/adm \
    db_name=mongodb \
    creation_statements='{ "db": "admin", "roles": [{ "role": "readWrite" }, {"role": "read", "db": "foo"}] }' \
    default_ttl="1h" \
    max_ttl="24h"


The following warnings were returned from the Vault server:
* Read access to this endpoint should be controlled via ACLs as it will return the connection details as is, including passwords, if any.
Success! Data written to: abc_mongodb/roles/adm
➜  bin git:(mongo-reconnect) ./vault read abc_mongodb/creds/adm      
Key            	Value
---            	-----
lease_id       	abc_mongodb/creds/adm/5372085e-c8bb-d1af-f82b-5c25ecb55a37
lease_duration 	1h0m0s
lease_renewable	true
password       	c7dfb1db-2da6-1908-4852-1e12af002897
username       	v-token-adm-mbZjA46vgTDSbbviwndE-1500506585

=========== here I run rs.stepDown() on mongo primary node ===========

➜  bin git:(mongo-reconnect) ./vault read abc_mongodb/creds/adm      
Error reading abc_mongodb/creds/adm: Error making API request.

URL: GET http://127.0.0.1:8200/v1/abc_mongodb/creds/adm
Code: 500. Errors:

* 1 error occurred:

* EOF

Logs from vault bellow:

➜  bin git:(mongo-reconnect) ./vault server -dev -dev-root-token-id='abc' -log-level=trace
==> Vault server configuration:

                     Cgo: disabled
         Cluster Address: https://127.0.0.1:8201
              Listener 1: tcp (addr: "127.0.0.1:8200", cluster address: "127.0.0.1:8201", tls: "disabled")
               Log Level: trace
                   Mlock: supported: true, enabled: false
        Redirect Address: http://127.0.0.1:8200
                 Storage: inmem
                 Version: Vault v0.7.3
             Version Sha: c8886bdcc83fb71ac5f9a795efadb0a02e408fda

==> WARNING: Dev mode is enabled!

In this mode, Vault is completely in-memory and unsealed.
Vault is configured to only have a single unseal key. The root
token has already been authenticated with the CLI, so you can
immediately begin using the Vault CLI.

The only step you need to take is to set the following
environment variables:

    export VAULT_ADDR='http://127.0.0.1:8200'

The unseal key and root token are reproduced below in case you
want to seal/unseal the Vault or play with authentication.

Unseal Key: 3lmAnpZnXsKCuuVGKnncByI/GUItczMfhDVTSkIb2ew=
Root Token: abc

==> Vault server started! Log data will stream in below:

2017/07/20 01:21:20.945099 [TRACE] physical/cache: creating LRU cache: size=32768
2017/07/20 01:21:20.945506 [TRACE] cluster listener addresses synthesized: cluster_addresses=[127.0.0.1:8201]
2017/07/20 01:21:20.945889 [INFO ] core: security barrier not initialized
2017/07/20 01:21:20.946195 [INFO ] core: security barrier initialized: shares=1 threshold=1
2017/07/20 01:21:20.946488 [TRACE] core: cluster name not found/set, generating new
2017/07/20 01:21:20.946513 [DEBUG] core: cluster name set: name=vault-cluster-4a9433e3
2017/07/20 01:21:20.946530 [TRACE] core: cluster ID not found, generating new
2017/07/20 01:21:20.946548 [DEBUG] core: cluster ID set: id=80e2c9a6-d94b-cd53-9b77-42ae3d239621
2017/07/20 01:21:20.946633 [INFO ] core: post-unseal setup starting
2017/07/20 01:21:20.946641 [TRACE] core: clearing forwarding clients
2017/07/20 01:21:20.946648 [TRACE] core: done clearing forwarding clients
2017/07/20 01:21:20.995236 [INFO ] core: loaded wrapping token key
2017/07/20 01:21:21.006185 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/20 01:21:21.006433 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/20 01:21:21.006788 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/20 01:21:21.006966 [INFO ] rollback: starting rollback manager
2017/07/20 01:21:21.009846 [INFO ] expiration: restoring leases
2017/07/20 01:21:21.009860 [DEBUG] expiration: collecting leases
2017/07/20 01:21:21.009880 [DEBUG] expiration: leases collected: num_existing=0
2017/07/20 01:21:21.015688 [INFO ] core: post-unseal setup complete
2017/07/20 01:21:21.016592 [INFO ] core: root token generated
2017/07/20 01:21:21.016611 [INFO ] core: pre-seal teardown starting
2017/07/20 01:21:21.016632 [INFO ] core: cluster listeners not running
2017/07/20 01:21:21.016665 [INFO ] rollback: stopping rollback manager
2017/07/20 01:21:21.016847 [INFO ] core: pre-seal teardown complete
2017/07/20 01:21:21.017078 [INFO ] core: vault is unsealed
2017/07/20 01:21:21.017132 [INFO ] core: post-unseal setup starting
2017/07/20 01:21:21.017158 [TRACE] core: clearing forwarding clients
2017/07/20 01:21:21.017165 [TRACE] core: done clearing forwarding clients
2017/07/20 01:21:21.017358 [INFO ] core: loaded wrapping token key
2017/07/20 01:21:21.017963 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/20 01:21:21.018263 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/20 01:21:21.018306 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/20 01:21:21.018431 [INFO ] rollback: starting rollback manager
2017/07/20 01:21:21.020335 [INFO ] expiration: restoring leases
2017/07/20 01:21:21.020347 [DEBUG] expiration: collecting leases
2017/07/20 01:21:21.020364 [DEBUG] expiration: leases collected: num_existing=0
2017/07/20 01:21:21.020952 [INFO ] core: post-unseal setup complete
2017/07/20 01:22:21.018927 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 01:22:21.018927 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 01:22:21.018944 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 01:22:21.019072 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 01:22:46.222190 [INFO ] core: successful mount: path=abc_mongodb/ type=database
2017/07/20 01:22:56.454124 [TRACE] database: operation=Initialize status=started type=mongodb
2017/07/20 01:22:56.510492 [TRACE] database: operation=Initialize status=finished type=mongodb verify=true err=<nil> took=56.361073ms
2017/07/20 01:23:05.896592 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 01:23:05.941431 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=44.839415ms
2017/07/20 01:23:20.643641 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 01:23:20.643951 [TRACE] database: operation=CreateUser status=finished type=mongodb err=EOF took=310.215µs
2017/07/20 01:23:21.019000 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 01:23:21.019010 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 01:23:21.019027 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 01:23:21.019034 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 01:23:21.019045 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 01:24:21.018793 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 01:24:21.018793 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 01:24:21.018805 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 01:24:21.018812 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 01:24:21.018880 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 01:25:21.018953 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 01:25:21.018962 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 01:25:21.018981 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 01:25:21.018987 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 01:25:21.018994 [TRACE] rollback: attempting rollback: path=abc_mongodb/
^C==> Vault shutdown triggered
2017/07/20 01:25:26.739112 [DEBUG] core: marked as sealed
2017/07/20 01:25:26.739157 [TRACE] core: clearing forwarding clients
2017/07/20 01:25:26.739185 [TRACE] core: done clearing forwarding clients
2017/07/20 01:25:26.739215 [INFO ] core: pre-seal teardown starting
2017/07/20 01:25:26.739244 [INFO ] core: cluster listeners not running
2017/07/20 01:25:26.739308 [INFO ] rollback: stopping rollback manager
2017/07/20 01:25:26.739376 [TRACE] database: operation=Close status=started type=mongodb
2017/07/20 01:25:26.739586 [TRACE] database: operation=Close status=finished type=mongodb err=<nil> took=213.229µs
2017/07/20 01:25:26.739866 [INFO ] core: pre-seal teardown complete
2017/07/20 01:25:26.739912 [DEBUG] core: sealing barrier
2017/07/20 01:25:26.739946 [INFO ] core: vault is sealed

@calvn
Copy link
Contributor

calvn commented Jul 20, 2017

From the mongoDB docs:

Upon successful stepdown, rs.stepDown() forces all clients currently connected to the database to disconnect. This helps ensure that the clients maintain an accurate view of the replica set.

You might have to restart the plugin to reset the connection: https://www.vaultproject.io/api/secret/databases/index.html#reset-connection

@drakeu
Copy link
Author

drakeu commented Jul 20, 2017

Thank you for this solution. As I wrote before 500 error occures when primary steps down. For my test case I use rs.stepDown() only to simulate this situation. But previously I have this situation when 3 node production replicaset change primary automaticaly. You can easy simulate this situation by killing primary node for previous example or if you use mongo replicaset in docker containers pause container with primary. In production environment mongodb replicaset can automaticaly change primary in many situations (network partitions, vm problems, hardware problems, etc). Or other situation - rolling maintenance (for example mongodb version upgrade). I think that is not expected production ready behaviour for vault when it have problems with connection to new primary (especially when it knows other members).
Bellow I paste logs when I kill current primary member (rest 2 node replicaset works normaly):

➜  bin git:(mongo-reconnect) ./vault server -dev -dev-root-token-id='abc' -log-level=trace
==> Vault server configuration:

                     Cgo: disabled
         Cluster Address: https://127.0.0.1:8201
              Listener 1: tcp (addr: "127.0.0.1:8200", cluster address: "127.0.0.1:8201", tls: "disabled")
               Log Level: trace
                   Mlock: supported: true, enabled: false
        Redirect Address: http://127.0.0.1:8200
                 Storage: inmem
                 Version: Vault v0.7.3
             Version Sha: c8886bdcc83fb71ac5f9a795efadb0a02e408fda

==> WARNING: Dev mode is enabled!

In this mode, Vault is completely in-memory and unsealed.
Vault is configured to only have a single unseal key. The root
token has already been authenticated with the CLI, so you can
immediately begin using the Vault CLI.

The only step you need to take is to set the following
environment variables:

    export VAULT_ADDR='http://127.0.0.1:8200'

The unseal key and root token are reproduced below in case you
want to seal/unseal the Vault or play with authentication.

Unseal Key: b0vesPiA1n8nsZId5MoqVS1b8G0oOqEJk+4dTrH/FuM=
Root Token: abc

==> Vault server started! Log data will stream in below:

2017/07/20 18:19:36.448118 [TRACE] physical/cache: creating LRU cache: size=32768
2017/07/20 18:19:36.450497 [TRACE] cluster listener addresses synthesized: cluster_addresses=[127.0.0.1:8201]
2017/07/20 18:19:36.453655 [INFO ] core: security barrier not initialized
2017/07/20 18:19:36.460296 [INFO ] core: security barrier initialized: shares=1 threshold=1
2017/07/20 18:19:36.469836 [TRACE] core: cluster name not found/set, generating new
2017/07/20 18:19:36.469883 [DEBUG] core: cluster name set: name=vault-cluster-9bb58a36
2017/07/20 18:19:36.469908 [TRACE] core: cluster ID not found, generating new
2017/07/20 18:19:36.469926 [DEBUG] core: cluster ID set: id=324e16f0-1700-bb17-689f-05155e65821e
2017/07/20 18:19:36.470540 [INFO ] core: post-unseal setup starting
2017/07/20 18:19:36.476060 [TRACE] core: clearing forwarding clients
2017/07/20 18:19:36.476099 [TRACE] core: done clearing forwarding clients
2017/07/20 18:19:36.568559 [INFO ] core: loaded wrapping token key
2017/07/20 18:19:36.636176 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/20 18:19:36.636549 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/20 18:19:36.639075 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/20 18:19:36.639432 [INFO ] rollback: starting rollback manager
2017/07/20 18:19:36.710475 [INFO ] expiration: restoring leases
2017/07/20 18:19:36.710513 [DEBUG] expiration: collecting leases
2017/07/20 18:19:36.710536 [DEBUG] expiration: leases collected: num_existing=0
2017/07/20 18:19:36.723782 [INFO ] core: post-unseal setup complete
2017/07/20 18:19:36.726470 [INFO ] core: root token generated
2017/07/20 18:19:36.726485 [INFO ] core: pre-seal teardown starting
2017/07/20 18:19:36.726508 [INFO ] core: cluster listeners not running
2017/07/20 18:19:36.726571 [INFO ] rollback: stopping rollback manager
2017/07/20 18:19:36.726745 [INFO ] core: pre-seal teardown complete
2017/07/20 18:19:36.727227 [INFO ] core: vault is unsealed
2017/07/20 18:19:36.727281 [INFO ] core: post-unseal setup starting
2017/07/20 18:19:36.727303 [TRACE] core: clearing forwarding clients
2017/07/20 18:19:36.727311 [TRACE] core: done clearing forwarding clients
2017/07/20 18:19:36.727503 [INFO ] core: loaded wrapping token key
2017/07/20 18:19:36.728138 [INFO ] core: successfully mounted backend: type=generic path=secret/
2017/07/20 18:19:36.728427 [INFO ] core: successfully mounted backend: type=system path=sys/
2017/07/20 18:19:36.728467 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2017/07/20 18:19:36.728628 [INFO ] rollback: starting rollback manager
2017/07/20 18:19:36.731360 [INFO ] expiration: restoring leases
2017/07/20 18:19:36.731375 [DEBUG] expiration: collecting leases
2017/07/20 18:19:36.731394 [DEBUG] expiration: leases collected: num_existing=0
2017/07/20 18:19:36.733847 [INFO ] core: post-unseal setup complete
2017/07/20 18:20:36.729336 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:20:36.729368 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:20:36.729392 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:20:36.729435 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:21:36.730133 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:21:36.730589 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:21:36.730914 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:21:36.731126 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:22:36.729046 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:22:36.729047 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:22:36.729072 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:22:36.729107 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:23:36.729084 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:23:36.729096 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:23:36.729111 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:23:36.729121 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:24:36.729077 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:24:36.729145 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:24:36.729155 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:24:36.729184 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:25:36.728971 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:25:36.729230 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:25:36.729380 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:25:36.729573 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:25:41.521359 [INFO ] core: successful mount: path=abc_mongodb/ type=database
2017/07/20 18:25:53.190125 [TRACE] database: operation=Initialize status=started type=mongodb
2017/07/20 18:25:53.283400 [TRACE] database: operation=Initialize status=finished type=mongodb verify=true err=<nil> took=93.252619ms
2017/07/20 18:26:19.093650 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 18:26:19.138108 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=44.460578ms
2017/07/20 18:26:21.232815 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 18:26:21.277152 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=44.334876ms
2017/07/20 18:26:27.588560 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 18:26:27.634534 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=45.969936ms
2017/07/20 18:26:36.729004 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:26:36.729244 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:26:36.729411 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:26:36.729550 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:26:36.729690 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 18:27:36.729063 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:27:36.729120 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:27:36.729129 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:27:36.729140 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:27:36.729144 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 18:28:36.729109 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:28:36.729113 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:28:36.729137 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:28:36.729146 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:28:36.729156 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 18:29:36.728969 [TRACE] rollback: attempting rollback: path=secret/
2017/07/20 18:29:36.729223 [TRACE] rollback: attempting rollback: path=sys/
2017/07/20 18:29:36.729373 [TRACE] rollback: attempting rollback: path=cubbyhole/
2017/07/20 18:29:36.729526 [TRACE] rollback: attempting rollback: path=abc_mongodb/
2017/07/20 18:29:36.729730 [TRACE] rollback: attempting rollback: path=auth/token/
2017/07/20 18:30:04.678273 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/20 18:30:04.678678 [TRACE] database: operation=CreateUser status=finished type=mongodb err=EOF took=403.641µs

I kill current primary:

➜  ~ date && ps aux | grep mongo
czw, 20 lip 2017, 18:29:30 CEST
drakeu    4284  1.6  1.3 915228 110028 ?       Sl   18:17   0:11 mongod --replSet replset --dbpath /tmp/data/replset/rs1/db --logpath /tmp/data/replset/rs1/mongod.log --port 27017 --logappend --fork
drakeu    4345  1.6  1.2 852740 100068 ?       Sl   18:17   0:11 mongod --replSet replset --dbpath /tmp/data/replset/rs2/db --logpath /tmp/data/replset/rs2/mongod.log --port 27018 --logappend --fork
drakeu    4374  1.6  1.2 847908 97436 ?        Sl   18:17   0:11 mongod --replSet replset --dbpath /tmp/data/replset/rs3/db --logpath /tmp/data/replset/rs3/mongod.log --port 27019 --logappend --fork
drakeu    5759  0.0  0.0  15464  1016 pts/19   S+   18:29   0:00 grep --color=auto --exclude-dir=.bzr --exclude-dir=CVS --exclude-dir=.git --exclude-dir=.hg --exclude-dir=.svn mongo
➜  ~ date && kill -9 4284
czw, 20 lip 2017, 18:29:51 CEST
➜  ~ date && ps aux | grep mongo
czw, 20 lip 2017, 18:29:55 CEST
drakeu    4345  1.6  1.2 852740 100068 ?       Sl   18:17   0:11 mongod --replSet replset --dbpath /tmp/data/replset/rs2/db --logpath /tmp/data/replset/rs2/mongod.log --port 27018 --logappend --fork
drakeu    4374  1.6  1.2 847908 97436 ?        Sl   18:17   0:11 mongod --replSet replset --dbpath /tmp/data/replset/rs3/db --logpath /tmp/data/replset/rs3/mongod.log --port 27019 --logappend --fork
drakeu    5814  0.0  0.0  15464   964 pts/19   S+   18:29   0:00 grep --color=auto --exclude-dir=.bzr --exclude-dir=CVS --exclude-dir=.git --exclude-dir=.hg --exclude-dir=.svn mongo

Vault not reconnect as previously:

➜  bin git:(mongo-reconnect) date && ./vault read abc_mongodb/creds/adm
czw, 20 lip 2017, 18:26:27 CEST
Key            	Value
---            	-----
lease_id       	abc_mongodb/creds/adm/bb5e2971-f3b0-94a3-2d57-8bd0bab9615e
lease_duration 	1h0m0s
lease_renewable	true
password       	33b92f45-6303-274b-c9ba-ae7c39194375
username       	v-token-adm-Gb3MHbX3RNFAAjN1X4AR-1500567987

➜  bin git:(mongo-reconnect) date && ./vault read abc_mongodb/creds/adm
czw, 20 lip 2017, 18:30:04 CEST
Error reading abc_mongodb/creds/adm: Error making API request.

URL: GET http://127.0.0.1:8200/v1/abc_mongodb/creds/adm
Code: 500. Errors:

* 1 error occurred:

* EOF


@calvn
Copy link
Contributor

calvn commented Jul 24, 2017

Did you try resetting/reloading the backend?

@jefferai jefferai modified the milestones: next-release, 0.7.4 Jul 24, 2017
@drakeu
Copy link
Author

drakeu commented Jul 24, 2017

Yes. Connection reset endpoint works when I trigger it from curl:
Command:

curl \
    --header "X-Vault-Token: abc" \
    --request POST \
    http://localhost:8200/v1/abc_mongodb/reset/mongodb

Logs:

2017/07/25 00:20:09.377859 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/25 00:20:09.378199 [TRACE] database: operation=CreateUser status=finished type=mongodb err=EOF took=339.354µs
2017/07/25 00:22:24.557075 [TRACE] database: operation=Close status=started type=mongodb
2017/07/25 00:22:24.557478 [TRACE] database: operation=Close status=finished type=mongodb err=<nil> took=401.966µs
2017/07/25 00:22:24.558869 [TRACE] database: operation=Initialize status=started type=mongodb
2017/07/25 00:22:24.610795 [TRACE] database: operation=Initialize status=finished type=mongodb verify=true err=<nil> took=51.919027ms
2017/07/25 00:22:44.130231 [TRACE] database: operation=CreateUser status=started type=mongodb
2017/07/25 00:22:44.174871 [TRACE] database: operation=CreateUser status=finished type=mongodb err=<nil> took=44.640279ms

This behaviour can be automatic? I mean - vault resets connection when recognize that current primary is now secondary?

@jefferai
Copy link
Member

That's what my branch is trying to do. It's not clear to me why it's not working but I haven't had a chance to circle back around to it.

@drakeu
Copy link
Author

drakeu commented Aug 17, 2017

Any progress?

@jefferai
Copy link
Member

No, I don't know of a way to check the connection state, and for some reason attempting to see and take action on the error isn't working.

@jeinwag
Copy link

jeinwag commented Dec 19, 2017

We ran into this issue after migrating from the deprecated MongoDB backend to the database backend. Never experienced it with the old backend.

Unfortunately, 0.8.3 doesn't fix it for us. After a change of the primary, any attempt to read database credentials from vault will block until it times out.

@jefferai jefferai reopened this Dec 19, 2017
@jefferai jefferai removed this from the 0.8.2 milestone Dec 19, 2017
@jefferai jefferai added this to the 0.9.1 milestone Dec 19, 2017
@jefferai
Copy link
Member

@jeinwag That was a very useful comment as it pointed us away from the EOF being the issue and back towards a difference between the old and new backends. I think I have a fix, which will go into 0.9.1 -- please try that when it's out and let us know.

jefferai added a commit that referenced this issue Dec 19, 2017
This was in the deprecated backend where it fixed a similar issue a long
time ago but for some reason didn't make it over. Additionally the
function wasn't being locked properly.

Hopefully fixes #2973
@jeinwag
Copy link

jeinwag commented Jan 8, 2018

OK, I just tested this with 0.9.1: I triggered a step down of the primary on the MongoDB cluster and tried reading credentials from the MongoDB backend. At first I got an EOF:
error reading database/creds/myservice: EOF

But an immediate second attempt was successful.

@jeinwag
Copy link

jeinwag commented Jan 8, 2018

There seems to be another issue related to this. After change of the MongoDB primary has happened, vault won't shut down properly:

vault[12801]: ==> Vault shutdown triggered
vault[12801]: 2018/01/08 15:28:54.756065 [WARN ] core: stopping active operation
vault[12801]: 2018/01/08 15:28:54.756313 [INFO ] physical/consul: Shutting down consul backend
vault[12801]: 2018/01/08 15:28:54.765355 [WARN ] physical/consul: Concurrent state change notify dropped
vault[12801]: 2018/01/08 15:28:54.765385 [INFO ] core: pre-seal teardown starting
vault[12801]: 2018/01/08 15:28:54.765393 [INFO ] core: stopping cluster listeners
vault[12801]: 2018/01/08 15:28:54.765401 [INFO ] core: shutting down forwarding rpc listeners
vault[12801]: 2018/01/08 15:28:54.765422 [INFO ] core: forwarding rpc listeners stopped
vault[12801]: 2018/01/08 15:28:54.917763 [INFO ] core: rpc listeners successfully shut down
vault[12801]: 2018/01/08 15:28:54.917808 [INFO ] core: cluster listeners successfully shut down
vault[12801]: 2018/01/08 15:28:54.917885 [INFO ] rollback: stopping rollback manager`

Then nothing after "stopping rollback manager".

@calvn
Copy link
Contributor

calvn commented Jan 8, 2018

I think I’ve found the potential issue, and will get back to you once I get a branch with the fix pushed.

@jeinwag
Copy link

jeinwag commented Jan 29, 2018

Just gave 0.9.3 a shot, looking good now! Thanks!

@zhecksum
Copy link

zhecksum commented Oct 26, 2019

On the newest version of Mongo (4.2), vault will not return an EOF error but will instead return "not master".

You've done some great work on fixing this issue (@jefferai and @calvn) and it would be awesome if you could add "not master" to the switch case statement. That will make the plugin work with 4.2 as well.

case err == io.EOF, strings.Contains(err.Error(), "EOF"):

to

case err == io.EOF, strings.Contains(err.Error(), "EOF"), strings.Contains(err.Error(), "not master"):

should fix it for mongo 4+!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
5 participants