Empty response on /auth/token/renew-self

[phaer]

Hi,

After we upgraded our Vault to v0.7.2 ('d28dd5a018294562dbc9a18c95554d52b5d12390'), we started to experience some issues. consul-template suddenly failed to renew its tokens:

2017/05/19 13:26:18.013552 [WARN] (view) vault.token: Put https://active.vault.service.consul:8200/v1/auth/token/renew-self: EOF (retry attempt 1 after "250ms")

The problem persisted after a restart of both, vault and consul-template, so I tried to reproduce it using curl and, sadly, succeeded:

$ curl --cert $MY_CERT --key $MY_KEY -H "X-Vault-Token: $MY_TOKEN"  -XPOST'https://active.vault.service.consul:8200/v1/auth/token/renew-self'
curl: (52) Empty reply from server

I would have expected either a renewed token or an error message instead of the empty reply. Most other features seem to continue working, consul-templates succeeds in fetching credentials during the initial period before it tries to renew the token.

Did I miss any relevant information? I did not see anything suspicious in the changelog.

[jefferai]

What is the error printed in Vault's log?

[phaer]

Sorry, it took me a while to reproduce the issue, because we had to downgrade meanwhile.

The following stacktrace seems to be most relevant

2017/05/23 10:45:01 http: panic serving 10.30.6.16:50730: runtime error: invalid memory address or nil pointer dereference
goroutine 18357 [running]:
net/http.(*conn).serve.func1(0xc421429900)
        /goroot/src/net/http/server.go:1721 +0xd0
panic(0x17cb6e0, 0x267e2a0)
        /goroot/src/runtime/panic.go:489 +0x2cf
github.com/hashicorp/vault/logical/framework.(*FieldData).Get(0x0, 0x1a5e47d, 0x4, 0xc421066778, 0x767357)
        /gopath/src/github.com/hashicorp/vault/logical/framework/field_data.go:54 +0x29
github.com/hashicorp/vault/builtin/credential/cert.(*backend).verifyCredentials(0xc4207216c0, 0xc421b617a0, 0x0, 0xc42062baee, 0x0, 0x0, 0xc421066af0)
        /gopath/src/github.com/hashicorp/vault/builtin/credential/cert/path_login.go:159 +0x258
github.com/hashicorp/vault/builtin/credential/cert.(*backend).pathLoginRenew(0xc4207216c0, 0xc421b617a0, 0x0, 0xc421066a90, 0x4e51a2, 0xc421066af0)
        /gopath/src/github.com/hashicorp/vault/builtin/credential/cert/path_login.go:103 +0x30a
github.com/hashicorp/vault/builtin/credential/cert.(*backend).(github.com/hashicorp/vault/builtin/credential/cert.pathLoginRenew)-fm(0xc421b617a0, 0x0, 0x0, 0x0, 0x100000000000024)
        /gopath/src/github.com/hashicorp/vault/builtin/credential/cert/backend.go:39 +0x3e
github.com/hashicorp/vault/logical/framework.(*Backend).handleAuthRenew(0xc420755860, 0xc421b617a0, 0xc421066ab0, 0x45c086, 0x30)
        /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:463 +0x1b3
github.com/hashicorp/vault/logical/framework.(*Backend).handleRevokeRenew(0xc420755860, 0xc421b617a0, 0xc420535650, 0x28, 0x28)
        /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:413 +0x424
github.com/hashicorp/vault/logical/framework.(*Backend).HandleRequest(0xc420755860, 0xc421b617a0, 0x0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:167 +0x7f6
github.com/hashicorp/vault/vault.(*Router).routeCommon(0xc4204eb770, 0xc421b617a0, 0x40f500, 0x0, 0x1a20000, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/router.go:326 +0x636
github.com/hashicorp/vault/vault.(*Router).Route(0xc4204eb770, 0xc421b617a0, 0x1a689bb, 0xb, 0xed0b60900)
        /gopath/src/github.com/hashicorp/vault/vault/router.go:218 +0x3a
github.com/hashicorp/vault/vault.(*ExpirationManager).renewAuthEntry(0xc4201d7db0, 0xc421b615e0, 0xc420a45560, 0x0, 0x0, 0x0, 0xc4341d0e98)
        /gopath/src/github.com/hashicorp/vault/vault/expiration.go:864 +0x1cc
github.com/hashicorp/vault/vault.(*ExpirationManager).RenewToken(0xc4201d7db0, 0xc421b615e0, 0xc420f50220, 0xf, 0xc420534f90, 0x24, 0x0, 0x0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/expiration.go:571 +0x410
github.com/hashicorp/vault/vault.(*TokenStore).handleRenew(0xc4205d5b90, 0xc421b615e0, 0xc420f50160, 0xc420f50170, 0xffffffffffffffff, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/token_store.go:1991 +0x17c
github.com/hashicorp/vault/vault.(*TokenStore).handleRenewSelf(0xc4205d5b90, 0xc421b615e0, 0xc420f50160, 0x5000104, 0x0, 0xffffffffffffffff)
        /gopath/src/github.com/hashicorp/vault/vault/token_store.go:1958 +0xcd
github.com/hashicorp/vault/vault.(*TokenStore).(github.com/hashicorp/vault/vault.handleRenewSelf)-fm(0xc421b615e0, 0xc420f50160, 0x0, 0x6, 0xc420754e58)
        /gopath/src/github.com/hashicorp/vault/vault/token_store.go:425 +0x3e
github.com/hashicorp/vault/logical/framework.(*Backend).HandleRequest(0xc420805ad0, 0xc421b615e0, 0x0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:221 +0x4c8
github.com/hashicorp/vault/vault.(*Router).routeCommon(0xc4204eb770, 0xc421b615e0, 0x0, 0x0, 0x5000000, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/router.go:326 +0x636
github.com/hashicorp/vault/vault.(*Router).Route(0xc4204eb770, 0xc421b615e0, 0xc421b615e0, 0xc420de95f0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/router.go:218 +0x3a
github.com/hashicorp/vault/vault.(*Core).handleRequest(0xc420214a80, 0xc421b615e0, 0x0, 0x0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:188 +0xb09
github.com/hashicorp/vault/vault.(*Core).HandleRequest(0xc420214a80, 0xc421b615e0, 0x0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:45 +0xc77
github.com/hashicorp/vault/http.request(0xc420214a80, 0x2631420, 0xc421b61500, 0xc4205f5600, 0xc421b615e0, 0x0, 0x0)
        /gopath/src/github.com/hashicorp/vault/http/handler.go:209 +0x3c
github.com/hashicorp/vault/http.handleLogical.func1(0x2631420, 0xc421b61500, 0xc4205f5600)
        /gopath/src/github.com/hashicorp/vault/http/logical.go:121 +0xfb
net/http.HandlerFunc.ServeHTTP(0xc420418b80, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:1942 +0x44
github.com/hashicorp/vault/http.handleRequestForwarding.func1(0x2631420, 0xc421b61500, 0xc4205f5600)
        /gopath/src/github.com/hashicorp/vault/http/handler.go:168 +0x761
net/http.HandlerFunc.ServeHTTP(0xc420418ba0, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:1942 +0x44
net/http.(*ServeMux).ServeHTTP(0xc4204ebf20, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:2238 +0x130
github.com/hashicorp/vault/http.wrapHelpHandler.func1(0x2631420, 0xc421b61500, 0xc4205f5600)
        /gopath/src/github.com/hashicorp/vault/http/help.go:22 +0x17f
net/http.HandlerFunc.ServeHTTP(0xc420418be0, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:1942 +0x44
github.com/hashicorp/vault/http.wrapGenericHandler.func1(0x2631420, 0xc421b61500, 0xc4205f5600)
        /gopath/src/github.com/hashicorp/vault/http/handler.go:86 +0xb1
net/http.HandlerFunc.ServeHTTP(0xc420418c00, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:1942 +0x44
net/http.serverHandler.ServeHTTP(0xc4201e7d90, 0x2631420, 0xc421b61500, 0xc4205f5600)
        /goroot/src/net/http/server.go:2568 +0x92
net/http.(*conn).serve(0xc421429900, 0x26325a0, 0xc420a78540)
        /goroot/src/net/http/server.go:1825 +0x612
created by net/http.(*Server).Serve
        /goroot/src/net/http/server.go:2668 +0x2ce
2017/05/23 10:46:44.238778 [INFO ] expire: revoked lease: lease_id=auth/cert/login/d176654490c07701f848514bdacab23af7174cf8

there are quite a few of them and, as far as I can see, every request to /auth/token/renew-self fails. Seemingly unrelated, there are a lot of entries like this:

2017/05/23 10:38:28.109615 [ERROR] expire: maximum revoke attempts reached: lease_id=mysql/creds/logrotate/c8e50a2d-bdda-930b-979d-8884ba6adaac

But they seem to be related to a missing permission in mysql and should not cause the behaviour above, I guess?

[jefferai]

What version of Vault is that stacktrace from?

[phaer]

Same as above (we tried to upgrade again, after fixing other things):

Storage: consul (HA available)
Version: Vault v0.7.2
Version Sha: d28dd5a018294562dbc9a18c95554d52b5d12390

[jefferai]

I've got a patch you can try if you're interested.

[phaer]

Thanks for the fast response! I am going to try your patch as soon as possible in a test environment.

[jefferai]

Cool -- see that PR above for it.

[phaer]

I can confirm that #2755 fixes the problem. 🎉