Panic on attempting MFA with DUO Security

[jeffreyb1232]

I set up user/password authentication to vault according to the instructions, then added DUO multi-factor authentication. I had this working on Thursday 10/19, but then Friday morning it was no longer working.

The client does the following:

> vault auth -method=userpass username=jeff
Password (will be hidden):
Put http://vault:8200/v1/auth/userpass/login/jeff: EOF

On the vault server, the console output is:

==> Vault server configuration:                                                                                                                                           

                 Backend: file                                                                                                                                            
              Listener 1: tcp (addr: "0.0.0.0:8200", cluster address: "", tls: "disabled")                                                                                
               Log Level: trace                                                                                                                                           
                   Mlock: supported: true, enabled: true                                                                                                                  
                 Version: Vault v0.6.2                                                                                                                                    

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

2016/10/26 08:11:48.327194 [INFO ] core: seal configuration missing, not initialized                                                                                      
2016/10/26 08:12:20.089590 [INFO ] core: security barrier not initialized                                                                                                 
2016/10/26 08:12:20.090020 [INFO ] core: security barrier initialized: shares=5 threshold=3                                                                               
2016/10/26 08:12:20.090248 [INFO ] core: post-unseal setup starting                                                                                                       
2016/10/26 08:12:20.091112 [INFO ] core: successfully mounted backend: type=generic path=secret/                                                                          
2016/10/26 08:12:20.091138 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/                                                                     
2016/10/26 08:12:20.091212 [INFO ] core: successfully mounted backend: type=system path=sys/                                                                              
2016/10/26 08:12:20.091337 [INFO ] rollback: starting rollback manager                                                                                                    
2016/10/26 08:12:20.092094 [INFO ] core: post-unseal setup complete                                                                                                       
2016/10/26 08:12:20.092340 [INFO ] core: root token generated                                                                                                             
2016/10/26 08:12:20.092353 [INFO ] core: pre-seal teardown starting                                                                                                       
2016/10/26 08:12:20.092364 [INFO ] rollback: stopping rollback manager                                                                                                    
2016/10/26 08:12:20.092379 [INFO ] core: pre-seal teardown complete                                                                                                       
2016/10/26 08:13:55.018717 [INFO ] core: vault is unsealed                                                                                                                
2016/10/26 08:13:55.018790 [INFO ] core: post-unseal setup starting                                                                                                       
2016/10/26 08:13:55.018983 [INFO ] core: successfully mounted backend: type=generic path=secret/                                                                          
2016/10/26 08:13:55.019005 [INFO ] core: successfully mounted backend: type=cubbyhole path=cubbyhole/                                                                     
2016/10/26 08:13:55.019130 [INFO ] core: successfully mounted backend: type=system path=sys/                                                                              
2016/10/26 08:13:55.019242 [INFO ] rollback: starting rollback manager                                                                                                    
2016/10/26 08:13:55.020152 [INFO ] core: post-unseal setup complete                                                                                                                                                                 2016/10/26 08:14:07.647367 [INFO ] core: enabled audit backend: path=file/ type=file                                                                                      
2016/10/26 08:14:07.864612 [INFO ] core: enabled credential backend: path=userpass/ type=userpass                                                                         
2016-10-26 08:15:18.605761 I | http: panic serving 172.18.0.1:59758: runtime error: invalid memory address or nil pointer dereference                                     
goroutine 88 [running]:                                                                                                                                                   
net/http.(*conn).serve.func1(0xc4207e6680)                                                                                                                                
        /goroot/src/net/http/server.go:1491 +0x12a                                                                                                                        
panic(0x12f6bc0, 0xc42000e040)                                                                                                                                            
        /goroot/src/runtime/panic.go:458 +0x243                                                                                                                           
github.com/hashicorp/vault/helper/mfa/duo.GetDuoAuthClient(0xc420438be0, 0xc4207f8aa0, 0x0, 0x0, 0x1201340, 0xc4201fd0f0)                                                 
        /gopath/src/github.com/hashicorp/vault/helper/mfa/duo/path_duo_access.go:72 +0x2ad                                                                                
github.com/hashicorp/vault/helper/mfa/duo.DuoHandler(0xc420438be0, 0xc4201fcc00, 0xc420013090, 0x3, 0xc42017ee58, 0x1)                                                    
        /gopath/src/github.com/hashicorp/vault/helper/mfa/duo/duo.go:41 +0x1fb                                                                                            
github.com/hashicorp/vault/helper/mfa.(*backend).wrapLoginHandler.func1(0xc420438be0, 0xc4201fcc00, 0x0, 0x6, 0xc4207fc8a8)                                               
        /gopath/src/github.com/hashicorp/vault/helper/mfa/mfa.go:81 +0x14f                                                                                                
github.com/hashicorp/vault/logical/framework.(*Backend).HandleRequest(0xc420327680, 0xc420438be0, 0xc420438be0, 0xc420262038, 0x19)                                       
        /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:206 +0x42e                                                                                    
github.com/hashicorp/vault/vault.(*Router).routeCommon(0xc4203ff680, 0xc420438be0, 0x0, 0x0, 0x1000000, 0x0, 0x0)                                                         
        /gopath/src/github.com/hashicorp/vault/vault/router.go:279 +0x75d                                                                                                 
github.com/hashicorp/vault/vault.(*Router).Route(0xc4203ff680, 0xc420438be0, 0x14ef2df, 0xb, 0x0)                                                                         
        /gopath/src/github.com/hashicorp/vault/vault/router.go:187 +0x3a                                                                                                  
github.com/hashicorp/vault/vault.(*Core).handleLoginRequest(0xc4201e9180, 0xc420438be0, 0x0, 0x0, 0x0, 0x0)                                                               
        /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:307 +0x1bd                                                                                       
github.com/hashicorp/vault/vault.(*Core).HandleRequest(0xc4201e9180, 0xc420438be0, 0x0, 0x0, 0x0)                                                                         
        /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:42 +0x18b                                                                                        
github.com/hashicorp/vault/http.request(0xc4201e9180, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0, 0xc420438be0, 0x0, 0x0)                                                      
        /gopath/src/github.com/hashicorp/vault/http/handler.go:192 +0x39                                                                                                  
github.com/hashicorp/vault/http.handleLogical.func1(0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                
        /gopath/src/github.com/hashicorp/vault/http/logical.go:111 +0x10e                                                                                                 
net/http.HandlerFunc.ServeHTTP(0xc4201e1380, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                       
        /goroot/src/net/http/server.go:1726 +0x44                                                                                                                         
github.com/hashicorp/vault/http.handleRequestForwarding.func1(0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                      
        /gopath/src/github.com/hashicorp/vault/http/handler.go:142 +0x76e                                                                                                 
net/http.HandlerFunc.ServeHTTP(0xc4201e13a0, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                       
        /goroot/src/net/http/server.go:1726 +0x44                                                                                                                         
net/http.(*ServeMux).ServeHTTP(0xc420265c80, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                       
        /goroot/src/net/http/server.go:2022 +0x7f                                                                                                                         
github.com/hashicorp/vault/http.handleHelpHandler.func1(0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                            
        /gopath/src/github.com/hashicorp/vault/http/help.go:18 +0xd8                                                                                                      
net/http.HandlerFunc.ServeHTTP(0xc4201e13e0, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                       
        /goroot/src/net/http/server.go:1726 +0x44                                                                                                                         
net/http.serverHandler.ServeHTTP(0xc42000cb80, 0x1db8a40, 0xc4200b1e10, 0xc42010a5a0)                                                                                     
        /goroot/src/net/http/server.go:2202 +0x7d                                                                                                                         
net/http.(*conn).serve(0xc4207e6680, 0x1db9c00, 0xc4207fabc0)                                                                                                             
        /goroot/src/net/http/server.go:1579 +0x4b7                                                                                                                        
created by net/http.(*Server).Serve                                                                                                                                       
        /goroot/src/net/http/server.go:2293 +0x44d                                                                                                                        

On Friday I didn't research the problem because I figured the DDOS attacks going on could effect the MFA services, but this week the problem persists. I've made sure the host configured for duo security is accessible from the server and DNS properly resolves the server to an IP address there. The traffic from the server is being run through a proxy server and I can see log entries from the proxy server indicating that a connection is happening to the correct domain name. I have tried running the vault server on 2 different hosts with the same result.

[riaan53]

Im getting the same panic when trying duo. Running Vault v0.6.2.

[broamski]

From the vault server, can you attempt to perform a connectivity test to the Duo service? Either via netcat or curl to https://<your DUO api endpoint/auth/v2/check. You should receive a 401 status reply.

[jgiles]

I am seeing this error right now.

@broamski can you advise on how to construct the duo API endpoint from the Vault config?

Since I am seeing this locally, I may take a stab at debugging it.

[jgiles]

The issue is sporadic, starting and stopping without any changes in okta/duo configuration. By the time I attempted the repro with a locally-built Vault (as opposed to a locally-executed 0.9.1 release), the issue was no longer occurring.

[jefferai]

A current panic would help, because the line being shown in the panic above doesn't correspond to anything useful in modern Vault. I didn't see anything around it that should be problematic, either.

[jgiles]

The line number I am seeing (in 0.9.1) is the same as the above:

vault/helper/mfa/duo/path_duo_access.go

Line 72 in 87b6919

return nil, fmt.Errorf("Could not connect to Duo: %s (%s)", *check.StatResult.Message, *check.StatResult.Message_Detail)

Based on https://help.duo.com/s/article/1338?language=en_US "A message_detail key may be present if additional information is available (like the specific parameter that caused the error)" that StatResult.Message_Detail is nil.

$ vault version
Vault v0.9.1 ('87b6919dea55da61d7cd444b2442cabb8ede8ab1')

Logs from earlier (pardon docker-compose line prefix):

vault_1     | 2018/01/22 22:30:09 http: panic serving 192.168.99.1:58002: runtime error: invalid memory address or nil pointer dereference
vault_1     | goroutine 523 [running]:
vault_1     | net/http.(*conn).serve.func1(0xc4209448c0)
vault_1     |   /goroot/src/net/http/server.go:1697 +0xd0
vault_1     | panic(0x1cf0c80, 0x3061ef0)
vault_1     |   /goroot/src/runtime/panic.go:491 +0x283
vault_1     | github.com/hashicorp/vault/helper/mfa/duo.GetDuoAuthClient(0xc420ac5e60, 0xc420341b00, 0x0, 0x0, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/helper/mfa/duo/path_duo_access.go:72 +0x250
vault_1     | github.com/hashicorp/vault/helper/mfa/duo.DuoHandler(0xc420ac5e60, 0xc4203fa6c0, 0xc4203c44b0, 0x3, 0xc42015eb18, 0x1)
vault_1     |   /gopath/src/github.com/hashicorp/vault/helper/mfa/duo/duo.go:41 +0x1dd
vault_1     | github.com/hashicorp/vault/helper/mfa.(*backend).wrapLoginHandler.func1(0xc420ac5e60, 0xc4203fa6c0, 0x0, 0x6, 0xc4209b5748)
vault_1     |   /gopath/src/github.com/hashicorp/vault/helper/mfa/mfa.go:81 +0x14b
vault_1     | github.com/hashicorp/vault/logical/framework.(*Backend).HandleRequest(0xc420435260, 0xc420ac5e60, 0x0, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/logical/framework/backend.go:231 +0x453
vault_1     | github.com/hashicorp/vault/vault.(*Router).routeCommon(0xc4203ce040, 0xc420ac5e60, 0x0, 0x0, 0x0, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/vault/router.go:510 +0x65f
vault_1     | github.com/hashicorp/vault/vault.(*Router).Route(0xc4203ce040, 0xc420ac5e60, 0x206b65f, 0xb, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/vault/router.go:372 +0x3a
vault_1     | github.com/hashicorp/vault/vault.(*Core).handleLoginRequest(0xc42044c800, 0xc420ac5e60, 0x0, 0x0, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:370 +0x562
vault_1     | github.com/hashicorp/vault/vault.(*Core).HandleRequest(0xc42044c800, 0xc420ac5e60, 0x0, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/vault/request_handling.go:48 +0x34d
vault_1     | github.com/hashicorp/vault/http.request(0xc42044c800, 0x3007240, 0xc42024ab60, 0xc4201a4700, 0xc420ac5e60, 0x0, 0x0)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/handler.go:230 +0x3c
vault_1     | github.com/hashicorp/vault/http.handleLogical.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/logical.go:122 +0xfb
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352e00, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | github.com/hashicorp/vault/http.handleRequestForwarding.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/handler.go:182 +0x1ca
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352e20, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | net/http.(*ServeMux).ServeHTTP(0xc4203b8ed0, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:2254 +0x130
vault_1     | github.com/hashicorp/vault/http.wrapHelpHandler.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/help.go:22 +0x166
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352e60, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | github.com/hashicorp/vault/http.wrapCORSHandler.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/cors.go:32 +0x10a
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352e80, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | github.com/hashicorp/vault/http.wrapGenericHandler.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/http/handler.go:109 +0xb1
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352ea0, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | github.com/hashicorp/vault/vendor/github.com/hashicorp/go-cleanhttp.PrintablePathCheckHandler.func1(0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /gopath/src/github.com/hashicorp/vault/vendor/github.com/hashicorp/go-cleanhttp/handlers.go:40 +0xcf
vault_1     | net/http.HandlerFunc.ServeHTTP(0xc420352ec0, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:1918 +0x44
vault_1     | net/http.serverHandler.ServeHTTP(0xc4209b4a90, 0x3007240, 0xc42024ab60, 0xc4201a4700)
vault_1     |   /goroot/src/net/http/server.go:2619 +0xb4
vault_1     | net/http.(*conn).serve(0xc4209448c0, 0x3008800, 0xc4202e2d00)
vault_1     |   /goroot/src/net/http/server.go:1801 +0x71d
vault_1     | created by net/http.(*Server).Serve
vault_1     |   /goroot/src/net/http/server.go:2720 +0x288

[jefferai]

Doh, somehow I was looking at line 62.

[jgiles]

@jefferai I don't think #3832 will fix - the line numbers at master are shifted one from the line numbers in v0.9.1 (see permalink above). The panic is on the line with the fmt.Errorf - if the problem was a nil check.StatResult the panic would be on v0.9.1 line 71 where we do if check.StatResult.Stat != "OK"

I think the problem has to be either check.StatResult.Message or check.StatResult.Message_Details - probably the details based on the doc.

[jefferai]

@jgiles Check master, that's already done.

[jgiles]

Ah I hadn't seen ec19c6c

Pardon the nitpick, but I don't think you want to throw out check.StatResult.Message if just check.StatResult.Message_Detail is null (which based on the docs is likely the problem case).

As an end-user, the panic itself isn't the problem; the problem is that you don't see any helpful error message.

[jefferai]

It's pretty unclear what one should expect at any time, especially given that key parts of their API don't behave as documented. (Their Go SDK is, somehow, even worse.) I'll attempt to figure something out though.

[jefferai]

This ought to do it: https://github.com/hashicorp/vault/pull/3834/files

[jgiles]

Thanks! Now next time this happens we'll have some idea what's actually going wrong with Duo.

[jeffreyb1232]

If you notice the date of my original post, the first day I encountered this problem happened to be the day of the DYN DNS attack in 2016. When I posted this, I hadn't put the two events together, but not long afterward I did. At the time I was prototyping this solution, but never returned to it after this failure. Edit... Oops, I just re-read the original post and I see that I did mention about the DDOS attacks.