Permissions Error Initializing Vault

[John Anderson]

I'm trying my first deploy of Vault w/ a Consul backend, and I'm running into problems getting Vault to properly initialize.

The problem I'm seeing is that looks like Consul is returning a 403: Permission Denied when any key that doesn't exist is requested.   Vault w/ it's ACL Token can read all keys that exist under vault/, however during initializing it tries to GET /v1/kv/vault/sys/expire/id/?keys&separator=%2F.   When it makes this request a 403 is returned.  However when it requests existing keys under the vault/ prefix, it is allowed to read them.

[johna@vault-01-phx ~]$ vault init -key-shares=5 -key-threshold=3 -pgp-keys=01.pub.key,02.pub.key,03.pub.key,04.pub.key,05.pub.key -root-token-pgp-key=01.pub.key > keys.txt
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.132733 [INFO ] core: security barrier not initialized
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.157006 [INFO ] core: security barrier initialized: shares=5 threshold=3
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.214969 [INFO ] core: post-unseal setup starting
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.243863 [INFO ] core: loaded wrapping token key
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.257487 [INFO ] core: successfully mounted backend: type=generic path=secret/
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.257545 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.257720 [INFO ] core: successfully mounted backend: type=system path=sys/
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.257855 [INFO ] rollback: starting rollback manager
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.291342 [INFO ] expiration: restoring leases
Aug 16 11:20:43 vault-01-phx consul-agent[14255]: 2017/08/16 11:20:43 [ERR] consul: RPC failed to server 10.10.3.135:8300: rpc error: Permission denied
Aug 16 11:20:43 vault-01-phx consul-agent[14255]: 2017/08/16 11:20:43 [ERR] http: Request GET /v1/kv/vault/sys/expire/id/?keys=&separator=%2F, error: rpc error: Permission denied from=127.0.0.1:57394
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.292942 [INFO ] core: pre-seal teardown starting
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.292973 [INFO ] core: cluster listeners not running
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.292999 [INFO ] rollback: stopping rollback manager
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.293122 [INFO ] core: pre-seal teardown complete
Aug 16 11:20:43 vault-01-phx vault[15638]: 2017/08/16 11:20:43.293159 [ERROR] core: post-unseal setup failed during init: error=expiration state restore failed: failed to scan for leases: list failed at path '': Unexpected response code: 403
...

The ACLs look like this:

{
  "Name": "Vault Token",
  "Type": "client",
  "ID": "<vault-key-uuid>",
  "Rules": " key \"vault\" { \"policy\" = \"write\" } node \"\" { \"policy\" = \"write\" } service \"vault\" { \"policy\" = \"write\" } agent \"\" { \"policy\" = \"write\" } session \"\" { \"policy\" = \"write\" } operator = \"read\""
}

When I browse Consul, with Vault's token, I can read anything under /kv/vault/, but explicitly requesting a key that doesn't exist returns an error.

[johna@vault-01-phx ~]$ curl -X GET -H 'X-Consul-Token: <vault-key-uuid>' 'http://localhost:8080/v1/kv/vault/sys/?keys'
["vault/sys/policy/default","vault/sys/policy/response-wrapping"]
[johna@vault-01-phx ~]$ curl -X GET -H 'X-Consul-Token: <vault-key-uuid>' 'http://localhost:8080/v1/kv/vault/sys/expire/?keys'
rpc error: rpc error: Permission deniedAug 16 11:30:51 vault-01-phx consul-agent[14255]: 2017/08/16 11:30:51 [ERR] consul: RPC failed to server 10.10.3.101:8300: rpc error: rpc error: Permission denied

What do I need to change in order to fix this?  Is it a problem in Vault (i.e. Vault should have created that key, or that key should exist)?   Is it a problem with Consul (i.e. Consul should not return a 403 in this case)?   Is it a problem with my ACLs (i.e. is there a way to return a 404 or other valid response from Consul when a key missing besides a 403)?

Here's some general information about my setup.

[johna@consul-01-phx ~]$ consul members
Node          Address           Status  Type    Build  Protocol  DC
phx-01        10.10.3.101:8301  alive   server  0.9.1  2         phx
phx-02        10.10.3.135:8301  alive   server  0.9.1  2         phx
phx-03        10.10.3.90:8301   alive   server  0.9.1  2         phx
vault-01-phx  10.10.3.198:8301  alive   client  0.9.1  2         phx
vault-02-phx  10.10.3.180:8301  alive   client  0.9.1  2         phx
[johna@consul-01-phx ~]$ consul --version
Consul v0.9.1
Protocol 2 spoken by default, understands 2 to 3 (agent will automatically use protocol >2 when speaking to compatible agents)
[johna@consul-01-phx ~]$ consul info
agent:
        check_monitors = 0
        check_ttls = 0
        checks = 0
        services = 0
build:
        prerelease =
        revision = 44704c6
        version = 0.9.1
consul:
        bootstrap = false
        known_datacenters = 2
        leader = false
        leader_addr = 10.10.3.135:8300
        server = true
raft:
        applied_index = 116837
        commit_index = 116837
        fsm_pending = 0
        last_contact = 13.853343ms
        last_log_index = 116837
        last_log_term = 65
        last_snapshot_index = 114695
        last_snapshot_term = 65
        latest_configuration = [{Suffrage:Voter ID:10.10.3.101:8300 Address:10.10.3.101:8300} {Suffrage:Voter ID:10.10.3.135:8300 Address:10.10.3.135:8300} {Suffrage:Voter ID:10.10.3.90:8300 Address:10.10.3.90:8300}]
        latest_configuration_index = 9
        num_peers = 2
        protocol_version = 2
        protocol_version_max = 3
        protocol_version_min = 0
        snapshot_version_max = 1
        snapshot_version_min = 0
        state = Follower
        term = 65
runtime:
        arch = amd64
        cpu_count = 4
        goroutines = 79
        max_procs = 4
        os = linux
        version = go1.8.3
serf_lan:
        coordinate_resets = 0
        encrypted = false
        event_queue = 0
        event_time = 22
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 67
        members = 5
        query_queue = 0
        query_time = 1
serf_wan:
        coordinate_resets = 0
        encrypted = false
        event_queue = 0
        event_time = 1
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 91
        members = 6
        query_queue = 0
        query_time = 1



[johna@consul-01-phx ~]$ consul info
agent:
        check_monitors = 0
        check_ttls = 0
        checks = 0
        services = 0
build:
        prerelease =
        revision = 44704c6
        version = 0.9.1
consul:
        bootstrap = false
        known_datacenters = 2
        leader = false
        leader_addr = 10.10.3.135:8300
        server = true
raft:
        applied_index = 116837
        commit_index = 116837
        fsm_pending = 0
        last_contact = 13.853343ms
        last_log_index = 116837
        last_log_term = 65
        last_snapshot_index = 114695
        last_snapshot_term = 65
        latest_configuration = [{Suffrage:Voter ID:10.10.3.101:8300 Address:10.10.3.101:8300} {Suffrage:Voter ID:10.10.3.135:8300 Address:10.10.3.135:8300} {Suffrage:Voter ID:10.10.3.90:8300 Address:10.10.3.90:8300}]
        latest_configuration_index = 9
        num_peers = 2
        protocol_version = 2
        protocol_version_max = 3
        protocol_version_min = 0
        snapshot_version_max = 1
        snapshot_version_min = 0
        state = Follower
        term = 65
runtime:
        arch = amd64
        cpu_count = 4
        goroutines = 79
        max_procs = 4
        os = linux
        version = go1.8.3
serf_lan:
        coordinate_resets = 0
        encrypted = false
        event_queue = 0
        event_time = 22
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 67
        members = 5
        query_queue = 0
        query_time = 1
serf_wan:
        coordinate_resets = 0
        encrypted = false
        event_queue = 0
        event_time = 1
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0


Vault v0.8.0 ('af63d879130d2ee292f09257571d371100a513eb')
[johna@vault-01-phx ~]$ vault status #After vault init command failed.
Sealed: true
Key Shares: 5
Key Threshold: 3
Unseal Progress: 0
Unseal Nonce:
Version: 0.8.0

High-Availability Enabled: true
        Mode: sealed

[Jeff Mitchell]

Hi John,

Consul had a regression in 0.9.1 that would lead to this. 0.9.2 came out last week and should address this issue.

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+unsubscribe@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/vault-tool/d2725b94-4dad-4d19-bde2-a2b41ed01405%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[John Anderson]

Thanks!

I'll rebuild the RPMs and upgrade my PoC environment to the latest version and let ya'll know how it goes.

John A.

[John Anderson]

Thanks for the fix, I'm confirming it worked.   Vault initialized properly.

Aug 21 13:47:39 vault-01-phx vault[19028]: ==> Vault server started! Log data will stream in below:
Aug 21 13:47:48 vault-01-phx vault[19028]: 2017/08/21 13:47:48.136449 [INFO ] core: seal configuration missing, not initialized
Aug 21 13:48:31 vault-01-phx vault[19028]: 2017/08/21 13:48:31.960676 [INFO ] core: security barrier not initialized
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.047659 [INFO ] core: security barrier not initialized
Aug
 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.082865 [INFO
 ] core: security barrier initialized: shares=5 threshold=3
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.144344 [INFO ] core: post-unseal setup starting
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.178337 [INFO ] core: loaded wrapping token key
Aug
 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.197976 [INFO
 ] core: successfully mounted backend: type=generic path=secret/
Aug
21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.198055 [INFO ]

 core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Aug

 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.198247 [INFO
 ] core: successfully mounted backend: type=system path=sys/
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.198416 [INFO ] rollback: starting rollback manager
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.232098 [INFO ] expiration: restoring leases
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.255799 [INFO ] core: post-unseal setup complete
Aug
 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.255818 [INFO
 ] core/startClusterListener: starting listener:
listener_address=0.0.0.0:8201
Aug 21 13:48:32 vault-01-phx
vault[19028]: 2017/08/21 13:48:32.256363 [INFO ]
core/startClusterListener: serving cluster requests:
cluster_listen_address=[::]:8201
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.280262 [INFO ] core: root token generated
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.280301 [INFO ] core: pre-seal teardown starting
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.280330 [INFO ] core: stopping cluster listeners
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.280405 [INFO ] core: shutting down forwarding rpc listeners
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.280534 [INFO ] core: forwarding rpc listeners stopped
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.756617 [INFO ] core: rpc listeners successfully shut down
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.756674 [INFO ] core: cluster listeners successfully shut down
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.756709 [INFO ] rollback: stopping rollback manager
Aug 21 13:48:32 vault-01-phx vault[19028]: 2017/08/21 13:48:32.756826 [INFO ] core: pre-seal teardown complete
Aug 21 14:45:47 vault-01-phx vault[19028]: 2017/08/21 14:45:47.840036 [INFO ] core: vault is unsealed
Aug 21 14:45:47 vault-01-phx vault[19028]: 2017/08/21 14:45:47.840128 [INFO ] core: entering standby mode
Aug 21 14:45:47 vault-01-phx vault[19028]: 2017/08/21 14:45:47.935489 [INFO ] core: acquired lock, enabling active operation
Aug 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.000909 [INFO ] core: post-unseal setup starting
Aug 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.006263 [INFO ] core: loaded wrapping token key
Aug
 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.011513 [INFO
 ] core: successfully mounted backend: type=generic path=secret/
Aug
21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.011806 [INFO ]

 core: successfully mounted backend: type=system path=sys/

Aug 21
14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.011852 [INFO ]
core: successfully mounted backend: type=cubbyhole path=cubbyhole/
Aug 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.012002 [INFO ] rollback: starting rollback manager
Aug 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.020670 [INFO ] expiration: restoring leases
Aug 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.027701 [INFO ] core: post-unseal setup complete
Aug
 21 14:45:48 vault-01-phx vault[19028]: 2017/08/21 14:45:48.027742 [INFO
 ] core/startClusterListener: starting listener:
listener_address=0.0.0.0:8201
Aug 21 14:45:48 vault-01-phx
vault[19028]: 2017/08/21 14:45:48.028075 [INFO ]
core/startClusterListener: serving cluster requests:
cluster_listen_address=[::]:8201
Aug 21 14:49:24 vault-01-phx vault[19028]: 2017/08/21 14:49:24.645905 [INFO ] core: successful mount: path=consul/ type=consul

I'm beginning to think I really don't understand the multi-datacenter model, as I can't "see" the vault data in the NLD consul servers after initializing the system in PHX, but I guess that's a new topic.

John A.