Vault randomly fails with 'error collecting acl policy keys: error=list failed at path '': context'

907 views
Skip to first unread message

David Alonim

unread,
Mar 22, 2019, 6:55:13 AM3/22/19
to Vault
Hello,

I've setup Vault on Kubernetes using CoreOS's Vault-Operator which uses CoreOS's ETCD-Operator.

Then I deployed a new vault 0.9.1 with 2 nodes, initialized and unsealed. I've enabled Kubernetes auth method and a new KV secret store and added a policy to allow access to the new KV store for my app.

Here is the container log from my previous pod:

==> Vault server configuration:

                     Cgo: disabled
         Cluster Address: https://staging-vault.vault.svc:8201
              Listener 1: tcp (addr: "0.0.0.0:8200", cluster address: "0.0.0.0:8201", tls: "enabled")
               Log Level: 
                   Mlock: supported: true, enabled: true
        Redirect Address: https://staging-vault.vault.svc:8200
                 Storage: etcd (HA available)
                 Version: Vault v0.9.1
             Version Sha: 87b6919dea55da61d7cd444b2442cabb8ede8ab1

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

2019/03/12 20:13:48.533550 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/13 10:24:31.422489 [INFO ] core: vault is unsealed
2019/03/13 10:24:31.422805 [INFO ] core: entering standby mode
2019/03/15 09:25:39.680457 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/15 09:25:41.710785 [ERROR] core: barrier init check failed: error=failed to check for initialization: rpc error: code = DeadlineExceeded desc = context deadline exceeded
2019/03/15 09:25:42.438586 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:14.478622 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:40.982897 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:42.506570 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:42.506594 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:42.507725 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:26:42.507746 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:16.858579 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:25.735890 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:31.096484 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:31.706671 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:37.464200 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:27:50.082600 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/15 09:27:55.235422 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:28:03 http: TLS handshake error from 100.96.251.105:60250: EOF
2019/03/15 09:28:03 http: TLS handshake error from 100.96.251.105:60364: EOF
2019/03/15 09:29:08 http: TLS handshake error from 127.0.0.1:49164: EOF
2019/03/15 09:29:41 http: TLS handshake error from 172.20.66.142:55206: EOF
2019/03/15 09:29:42 http: TLS handshake error from 100.96.251.105:35392: EOF
2019/03/15 09:40:02 http: TLS handshake error from 172.20.66.142:63932: EOF
2019/03/15 09:40:08 http: TLS handshake error from 100.96.251.105:38092: EOF
2019/03/15 09:40:35 http: TLS handshake error from 100.96.251.105:38196: EOF
2019/03/15 09:40:50 http: TLS handshake error from 100.96.251.105:38286: EOF
2019/03/15 09:41:07.526713 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:41:10 http: TLS handshake error from 100.96.251.105:38390: EOF
2019/03/15 09:41:29.842552 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:41:36 http: TLS handshake error from 100.96.251.105:38502: EOF
2019/03/15 09:41:36.186182 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:41:36.187547 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:41:41.213014 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 09:41:41.217798 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/15 09:41:54 http: TLS handshake error from 100.96.251.105:38590: EOF
2019/03/15 09:42:04 http: TLS handshake error from 172.20.66.142:64708: EOF
2019/03/15 09:42:08 http: TLS handshake error from 172.20.66.142:64732: EOF
2019/03/15 09:42:08 http: TLS handshake error from 100.96.251.105:38682: EOF
2019/03/15 09:43:23 http: TLS handshake error from 172.20.66.142:65266: EOF
2019/03/15 09:43:26 http: TLS handshake error from 100.96.251.105:39018: EOF
2019/03/15 09:43:53 http: TLS handshake error from 172.20.66.142:65408: EOF
2019/03/15 11:13:18.520120 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/15 11:13:18.521089 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/15 11:13:18 http: TLS handshake error from 172.20.66.142:63260: EOF
2019/03/15 11:13:43 http: TLS handshake error from 172.20.66.142:63286: EOF
2019/03/15 11:14:05 http: TLS handshake error from 172.20.66.142:63338: EOF
2019/03/15 11:14:22 http: TLS handshake error from 100.96.251.105:42220: EOF
2019/03/15 11:14:24 http: TLS handshake error from 172.20.66.142:63316: EOF
2019/03/15 11:14:26 http: TLS handshake error from 100.96.251.105:42320: EOF
2019/03/15 11:14:29.256861 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/15 11:14:30 http: TLS handshake error from 172.20.66.142:63538: EOF
2019/03/15 11:15:20 http: TLS handshake error from 172.20.66.142:63610: EOF
2019/03/15 11:15:20 http: TLS handshake error from 100.96.251.105:42434: EOF
2019/03/15 11:15:21 http: TLS handshake error from 172.20.66.142:63632: EOF
2019/03/15 11:15:21 http: TLS handshake error from 172.20.66.142:63362: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63658: EOF
2019/03/15 11:15:50 http: TLS handshake error from 100.96.251.105:42630: EOF
2019/03/15 11:15:50 http: TLS handshake error from 100.96.251.105:42744: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:64010: EOF
2019/03/15 11:15:50 http: TLS handshake error from 100.96.251.105:42844: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:64036: EOF
2019/03/15 11:15:50 http: TLS handshake error from 127.0.0.1:56922: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63980: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63682: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63802: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63934: EOF
2019/03/15 11:15:50 http: TLS handshake error from 100.96.251.105:42536: EOF
2019/03/15 11:15:50 http: TLS handshake error from 172.20.66.142:63958: EOF
2019/03/15 12:26:36.784209 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 08:14:17.193282 [ERROR] core: failed to acquire lock: error=etcdserver: requested lease not found
2019/03/18 09:50:27.259132 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 09:50:32.877990 [ERROR] core: failed to acquire lock: error=etcdserver: requested lease not found
2019/03/18 09:50:43.156745 [INFO ] core: acquired lock, enabling active operation
2019/03/18 09:50:43.668660 [INFO ] core: post-unseal setup starting
2019/03/18 09:50:43.677162 [INFO ] core: loaded wrapping token key
2019/03/18 09:50:43.677245 [INFO ] core: successfully setup plugin catalog: plugin-directory=
2019/03/18 09:50:43.690360 [INFO ] core: successfully mounted backend: type=kv path=secret/
2019/03/18 09:50:43.690739 [INFO ] core: successfully mounted backend: type=system path=sys/
2019/03/18 09:50:43.691179 [INFO ] core: successfully mounted backend: type=identity path=identity/
2019/03/18 09:50:43.691279 [INFO ] core: successfully mounted backend: type=kv path=my-kv/
2019/03/18 09:50:43.691313 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2019/03/18 09:50:43.712852 [INFO ] expiration: restoring leases
2019/03/18 09:50:43.713057 [INFO ] rollback: starting rollback manager
2019/03/18 09:50:43.718919 [INFO ] expiration: lease restore complete
2019/03/18 09:50:43.723564 [INFO ] identity: entities restored
2019/03/18 09:50:43.726207 [INFO ] identity: groups restored
2019/03/18 09:50:43.729081 [INFO ] core: post-unseal setup complete
2019/03/18 09:50:43.729132 [INFO ] core/startClusterListener: starting listener: listener_address=0.0.0.0:8201
2019/03/18 09:50:43.729379 [INFO ] core/startClusterListener: serving cluster requests: cluster_listen_address=[::]:8201
2019/03/18 10:16:03.402363 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:05:21.842558 [WARN ] core: leadership lost, stopping active operation
2019/03/18 14:05:21.865025 [INFO ] core: pre-seal teardown starting
2019/03/18 14:05:21.865730 [INFO ] core: stopping cluster listeners
2019/03/18 14:05:21.865892 [INFO ] core: shutting down forwarding rpc listeners
2019/03/18 14:05:21.866187 [INFO ] core: forwarding rpc listeners stopped
2019/03/18 14:05:23.550983 [INFO ] core: rpc listeners successfully shut down
2019/03/18 14:05:25.069732 [INFO ] core: cluster listeners successfully shut down
2019/03/18 14:05:25.069769 [INFO ] rollback: stopping rollback manager
2019/03/18 14:05:25.113531 [INFO ] core: pre-seal teardown complete
2019/03/18 14:05:25.184507 [INFO ] core: acquired lock, enabling active operation
2019/03/18 14:05:27.110742 [INFO ] core: post-unseal setup starting
2019/03/18 14:05:27.117603 [INFO ] core: loaded wrapping token key
2019/03/18 14:05:27.118076 [INFO ] core: successfully setup plugin catalog: plugin-directory=
2019/03/18 14:05:27.128822 [INFO ] core: successfully mounted backend: type=kv path=secret/
2019/03/18 14:05:27.130897 [INFO ] core: successfully mounted backend: type=system path=sys/
2019/03/18 14:05:27.131481 [INFO ] core: successfully mounted backend: type=identity path=identity/
2019/03/18 14:05:27.131524 [INFO ] core: successfully mounted backend: type=kv path=my-kv/
2019/03/18 14:05:27.131604 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2019/03/18 14:05:27.191286 [INFO ] expiration: restoring leases
2019/03/18 14:05:27.191496 [INFO ] rollback: starting rollback manager
2019/03/18 14:05:27.209700 [INFO ] expiration: lease restore complete
2019/03/18 14:05:27.222668 [INFO ] identity: entities restored
2019/03/18 14:05:27.229175 [INFO ] identity: groups restored
2019/03/18 14:05:27.241051 [INFO ] core: post-unseal setup complete
2019/03/18 14:05:27.241100 [INFO ] core/startClusterListener: starting listener: listener_address=0.0.0.0:8201
2019/03/18 14:05:27.241205 [INFO ] core/startClusterListener: serving cluster requests: cluster_listen_address=[::]:8201
2019/03/18 14:06:00.762924 [WARN ] core: leadership lost, stopping active operation
2019/03/18 14:06:10 http: TLS handshake error from 172.20.66.142:19384: EOF
2019/03/18 14:06:23 http: TLS handshake error from 172.20.66.142:19412: EOF
2019/03/18 14:06:27.676716 [ERROR] core: clearing leader advertisement failed: error=context deadline exceeded
2019/03/18 14:06:27.681021 [INFO ] core: pre-seal teardown starting
2019/03/18 14:06:27.682616 [INFO ] core: stopping cluster listeners
2019/03/18 14:06:27.686886 [INFO ] core: shutting down forwarding rpc listeners
2019/03/18 14:06:27.688134 [INFO ] core: forwarding rpc listeners stopped
2019/03/18 14:06:29.030626 [INFO ] core: rpc listeners successfully shut down
2019/03/18 14:06:29.030663 [INFO ] core: cluster listeners successfully shut down
2019/03/18 14:06:29.030687 [INFO ] rollback: stopping rollback manager
2019/03/18 14:06:32 http: TLS handshake error from 172.20.66.142:19438: EOF
2019/03/18 14:06:32 http: TLS handshake error from 100.96.251.105:58510: EOF
2019/03/18 14:06:32 http: TLS handshake error from 100.96.251.105:58412: EOF
2019/03/18 14:06:38 http: TLS handshake error from 172.20.66.142:19466: EOF
2019/03/18 14:06:38.752838 [ERROR] rollback: error rolling back: path=cubbyhole/ error=failed to read salt: context deadline exceeded
2019/03/18 14:06:38.758968 [INFO ] core: pre-seal teardown complete
2019/03/18 14:06:44.010521 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:06:44.285498 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:06:51.558957 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:06:59.138594 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:07:27.910581 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:07:37.688593 [ERROR] core: key rotation periodic upgrade check failed: error=context deadline exceeded
2019/03/18 14:07:39.471141 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:07:54 http: TLS handshake error from 100.96.251.105:58734: EOF
2019/03/18 14:07:54.735844 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:00.829026 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:00 http: TLS handshake error from 127.0.0.1:38718: EOF
2019/03/18 14:08:00 http: TLS handshake error from 100.96.251.105:58830: EOF
2019/03/18 14:08:01 http: TLS handshake error from 100.96.251.105:58926: EOF
2019/03/18 14:08:02.991699 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:06.529712 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:07.207822 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:07.237324 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:07.410560 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:17.307982 [INFO ] core: acquired lock, enabling active operation
2019/03/18 14:08:19.209215 [INFO ] core: post-unseal setup starting
2019/03/18 14:08:19.220705 [INFO ] core: loaded wrapping token key
2019/03/18 14:08:19.222903 [INFO ] core: successfully setup plugin catalog: plugin-directory=
2019/03/18 14:08:19.243679 [INFO ] core: successfully mounted backend: type=kv path=secret/
2019/03/18 14:08:19.248400 [INFO ] core: successfully mounted backend: type=system path=sys/
2019/03/18 14:08:19.250909 [INFO ] core: successfully mounted backend: type=identity path=identity/
2019/03/18 14:08:19.259334 [INFO ] core: successfully mounted backend: type=kv path=my-kv/
2019/03/18 14:08:19.261112 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2019/03/18 14:08:20.548805 [INFO ] expiration: restoring leases
2019/03/18 14:08:20.549241 [INFO ] rollback: starting rollback manager
2019/03/18 14:08:20.559529 [INFO ] expiration: lease restore complete
2019/03/18 14:08:20.660887 [INFO ] identity: entities restored
2019/03/18 14:08:21.318880 [INFO ] identity: groups restored
2019/03/18 14:08:21.328345 [INFO ] core: post-unseal setup complete
2019/03/18 14:08:21.328840 [INFO ] core/startClusterListener: starting listener: listener_address=0.0.0.0:8201
2019/03/18 14:08:21.329670 [INFO ] core/startClusterListener: serving cluster requests: cluster_listen_address=[::]:8201
2019/03/18 14:08:34.691546 [WARN ] core: leadership lost, stopping active operation
2019/03/18 14:08:38.621503 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:38.627344 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:43.228033 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:08:57.958133 [ERROR] core: clearing leader advertisement failed: error=context deadline exceeded
2019/03/18 14:08:57.969978 [INFO ] core: pre-seal teardown starting
2019/03/18 14:08:57.970297 [INFO ] core: stopping cluster listeners
2019/03/18 14:08:57.970626 [INFO ] core: shutting down forwarding rpc listeners
2019/03/18 14:08:57.970829 [INFO ] core: forwarding rpc listeners stopped
2019/03/18 14:08:57 http: TLS handshake error from 172.20.66.142:20212: EOF
2019/03/18 14:08:58.486534 [INFO ] core: rpc listeners successfully shut down
2019/03/18 14:08:58.486562 [INFO ] core: cluster listeners successfully shut down
2019/03/18 14:08:58.486588 [INFO ] rollback: stopping rollback manager
2019/03/18 14:08:58.486690 [INFO ] core: pre-seal teardown complete
2019/03/18 14:09:03.499055 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:09:03.595702 [INFO ] core: acquired lock, enabling active operation
2019/03/18 14:09:05.533827 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:09:05.929915 [INFO ] core: post-unseal setup starting
2019/03/18 14:09:05.932948 [INFO ] core: loaded wrapping token key
2019/03/18 14:09:05.933103 [INFO ] core: successfully setup plugin catalog: plugin-directory=
2019/03/18 14:09:06.331023 [INFO ] core: successfully mounted backend: type=kv path=secret/
2019/03/18 14:09:06.950576 [INFO ] core: successfully mounted backend: type=system path=sys/
2019/03/18 14:09:06.997868 [INFO ] core: successfully mounted backend: type=identity path=identity/
2019/03/18 14:09:06.997925 [INFO ] core: successfully mounted backend: type=kv path=my-kv/
2019/03/18 14:09:07.408387 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
2019/03/18 14:09:07.407378 [ERROR] core: barrier init check failed: error=failed to check for initialization: context deadline exceeded
2019/03/18 14:09:13.578570 [ERROR] error collecting acl policy keys: error=list failed at path '': context deadline exceeded
==> Vault shutdown triggered


The error that caused the shutdown has to do something with acl policies but all I've got are this policies:

vault policy list       
default
my-policy
root

How do you start debugging this?

Thank you

Jeff Mitchell

unread,
Mar 25, 2019, 9:59:57 AM3/25/19
to Vault
Hi David,

Is there a reason on a new setup you're using etcd (which we don't support) and a very old version of Vault that we also don't support? There could be many possible answers to your issue, but since many of those have been addressed in more recent versions of Vault you're likely best off by upgrading first.

Best,
Jeff

--
This mailing list is governed under the HashiCorp Community Guidelines - https://www.hashicorp.com/community-guidelines.html. Behavior in violation of those guidelines may result in your removal from this mailing list.
 
GitHub Issues: https://github.com/hashicorp/vault/issues
IRC: #vault-tool on Freenode
---
You received this message because you are subscribed to the Google Groups "Vault" group.
To unsubscribe from this group and stop receiving emails from it, send an email to vault-tool+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/vault-tool/865a39e9-bc08-4e85-9815-0610642c67ad%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.
Message has been deleted

David Alonim

unread,
Mar 25, 2019, 10:43:38 AM3/25/19
to Vault
Hey Jeff,

I am using etcd because this is the only storage backend supported by the Vault operator I've installed on my Kubernetes cluster. I will try to deploy Vault using a different setup and an upgraded version of Vault and report back.

Thank you very much!
Reply all
Reply to author
Forward
0 new messages