Can't get Auth Token when setting up Active Directory Access Control

Archive Rancher 1.x
1

I’m trying to setup Active Directory for Access Control but I keep getting a “Failed to get Auth token.” error message - I am pretty sure the service is able to connect and authenticate me, but something else is breaking? I see this in the cattle debug log (well, here is the topline of the message, its a really long stack trace):

[.a.a.i.e.ExternalServiceAuthProvider] Failed to get token from Auth Service. org.apache.http.NoHttpResponseException: The target server failed to respond
       at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143) ~[httpclient-4.3.1.jar:4.3.1]

I’ve got other services able to connect and authenticate to AD, its just a basic, no TLS, AD deployment.

2

Can you share a bigger portion of the rancher/server container logs around this error? You can clip off most of the stack trace though.

3

Sure, here you go:

2017-09-14 23:34:20,193 INFO  [:] [] [] [] [ecutorService-2] [.c.p.a.e.i.ArchaiusEventListenerImpl] Refreshing settings
2017-09-14 23:34:20,218 INFO  [:] [] [] [] [ecutorService-6] [.c.p.a.e.i.ArchaiusEventListenerImpl] Refreshing settings
2017-09-14 23:34:20,255 INFO  [:] [] [] [] [cutorService-10] [.c.p.a.e.i.ArchaiusEventListenerImpl] Refreshing settings
2017-09-14 23:34:20,286 INFO  [:] [] [] [] [ecutorService-3] [.c.p.a.e.i.ArchaiusEventListenerImpl] Refreshing settings
2017-09-14 23:34:20,661 ERROR [:] [] [] [] [p1020391880-193] [.a.a.i.e.ExternalServiceAuthProvider] Failed to get token from Auth Service. org.apache.http.NoHttpResponseException: The target server failed to respond
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260) ~[httpcore-4.3.jar:4.3]
        at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:161) ~[httpcore-4.3.jar:4.3]
        at sun.reflect.GeneratedMethodAccessor570.invoke(Unknown Source) ~[na:na]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_72]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_72]
        at org.apache.http.impl.conn.CPoolProxy.invoke(CPoolProxy.java:138) ~[httpclient-4.3.1.jar:4.3.1]
        at com.sun.proxy.$Proxy82.receiveResponseHeader(Unknown Source) ~[na:na]
        at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271) ~[httpcore-4.3.jar:4.3]
        at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123) ~[httpcore-4.3.jar:4.3]
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:253) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:194) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:85) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:186) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) ~[httpclient-4.3.1.jar:4.3.1]
        at org.apache.http.client.fluent.Request.execute(Request.java:143) ~[fluent-hc-4.3.1.jar:4.3.1]
        at io.cattle.platform.iaas.api.auth.integration.external.ExternalServiceAuthProvider.getToken(ExternalServiceAuthProvider.java:80) ~[cattle-iaas-auth-logic-0.5.0-SNAPSHOT.jar:na]
        at io.cattle.platform.iaas.api.auth.identity.TokenResourceManager.createToken(TokenResourceManager.java:105) [cattle-iaas-auth-logic-0.5.0-SNAPSHOT.jar:na]
<REMOVED MOST OF STACK TRACE>
2017-09-14 23:35:17,019 INFO  [:] [] [] [] [p1020391880-187] [i.c.p.c.s.impl.ConfigItemServerImpl ] Processing [metadata-answers] for client [agent:4]
2017-09-14 23:35:17,092 INFO  [:] [] [] [] [p1020391880-176] [i.c.p.c.s.impl.ConfigItemServerImpl ] Setting item [metadata-answers] to version [1331-4f3c5c96fb170da7fa8781d4ac55192c] for [agent:4]
4

Also, validated I can connect to the server from the rancher/server container:

$ docker exec -it 59683229796c nc -z -v -w5 192.168.1.5 389
Connection to 192.168.1.5 389 port [tcp/ldap] succeeded!
5

I have exactly the same issue with our Siemens Active Directory server. It confirms bot accounts (service and test account) and finishes the request, but Rancher fails with an ‘Failed to get Auth token.’. The detailed log from Rancher Server is:

time=“2017-10-24T07:12:05Z” level=info msg="newProvider ldap"
time=“2017-10-24T07:12:05Z” level=info msg="Calling reload"
time=“2017-10-24T07:12:05Z” level=info msg="Auth provider configured ldapconfig"
time=“2017-10-24T07:12:05Z” level=info msg="Auth provider configured ldapconfig"
time=“2017-10-24T07:12:05Z” level=info msg="Now generating Ldap token"
2017/10/24 07:12:05 http: panic serving 127.0.0.1:56024: runtime error: index out of range
goroutine 1037 [running]:
net/http.(*conn).serve.func1(0xc4209b40a0)
/usr/local/go/src/net/http/server.go:1721 +0xd0
panic(0xb8cca0, 0x11b0d10)
/usr/local/go/src/runtime/panic.go:489 +0x2cf
github.com/rancher/rancher-auth-service/providers/ldap.(*LClient).GenerateToken(0xc420cce680, 0xc420622420, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, …)
/go/src/github.com/rancher/rancher-auth-service/providers/ldap/ldap_client.go:157 +0xd3f
github.com/rancher/rancher-auth-service/providers/ldap/ad.(*ADProvider).GenerateToken(0xc4202b6030, 0xc420622420, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, …)
/go/src/github.com/rancher/rancher-auth-service/providers/ldap/ad/ad_provider.go:88 +0x7d
github.com/rancher/rancher-auth-service/server.CreateToken(0xc420622420, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, …)
/go/src/github.com/rancher/rancher-auth-service/server/auth_server.go:866 +0x8a
github.com/rancher/rancher-auth-service/service.CreateToken(0x11d15e0, 0xc420a270a0, 0xc42049b600)
/go/src/github.com/rancher/rancher-auth-service/service/route_handlers.go:45 +0x6cb
net/http.HandlerFunc.ServeHTTP(0xc53eb8, 0x11d15e0, 0xc420a270a0, 0xc42049b600)
/usr/local/go/src/net/http/server.go:1942 +0x44
github.com/rancher/rancher-auth-service/vendor/github.com/rancher/go-rancher/api.ApiHandler.func1(0x11d15e0, 0xc420a270a0, 0xc42049b600)
/go/src/github.com/rancher/rancher-auth-service/vendor/github.com/rancher/go-rancher/api/handler.go:20 +0x131
net/http.HandlerFunc.ServeHTTP(0xc42034a7a0, 0x11d15e0, 0xc420a270a0, 0xc42049b600)
/usr/local/go/src/net/http/server.go:1942 +0x44
github.com/rancher/rancher-auth-service/vendor/github.com/gorilla/context.ClearHandler.func1(0x11d15e0, 0xc420a270a0, 0xc42049b600)
/go/src/github.com/rancher/rancher-auth-service/vendor/github.com/gorilla/context/context.go:141 +0x8b
net/http.HandlerFunc.ServeHTTP(0xc42034a7c0, 0x11d15e0, 0xc420a270a0, 0xc42049b600)
/usr/local/go/src/net/http/server.go:1942 +0x44
github.com/rancher/rancher-auth-service/vendor/github.com/gorilla/mux.(*Router).ServeHTTP(0xc4202baeb0, 0x11d15e0, 0xc420a270a0, 0xc42049b600)
/go/src/github.com/rancher/rancher-auth-service/vendor/github.com/gorilla/mux/mux.go:107 +0x10c
net/http.serverHandler.ServeHTTP(0xc42071c160, 0x11d15e0, 0xc420a270a0, 0xc42049b400)
/usr/local/go/src/net/http/server.go:2568 +0x92
net/http.(*conn).serve(0xc4209b40a0, 0x11d1e20, 0xc420c8e980)
/usr/local/go/src/net/http/server.go:1825 +0x612
created by net/http.(*Server).Serve
/usr/local/go/src/net/http/server.go:2668 +0x2ce
2017-10-24 07:12:05,831 ERROR [:] [] [] [] [p1020391880-332] [.a.a.i.e.ExternalServiceAuthProvider] Failed to get token from Auth Service. org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260) ~[httpcore-4.3.jar:4.3]
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:161) ~[httpcore-4.3.jar:4.3]
at sun.reflect.GeneratedMethodAccessor436.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_72]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_72]
at org.apache.http.impl.conn.CPoolProxy.invoke(CPoolProxy.java:138) ~[httpclient-4.3.1.jar:4.3.1]
at com.sun.proxy.$Proxy88.receiveResponseHeader(Unknown Source) ~[na:na]
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271) ~[httpcore-4.3.jar:4.3]
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123) ~[httpcore-4.3.jar:4.3]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:253) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:194) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:85) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:186) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) ~[httpclient-4.3.1.jar:4.3.1]
at org.apache.http.client.fluent.Request.execute(Request.java:143) ~[fluent-hc-4.3.1.jar:4.3.1]
at io.cattle.platform.iaas.api.auth.integration.external.ExternalServiceAuthProvider.getToken(ExternalServiceAuthProvider.java:80) ~[cattle-iaas-auth-logic-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.iaas.api.auth.identity.TokenResourceManager.createToken(TokenResourceManager.java:105) [cattle-iaas-auth-logic-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.iaas.api.auth.identity.TokenResourceManager.createInternal(TokenResourceManager.java:82) [cattle-iaas-auth-logic-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.resource.impl.AbstractBaseResourceManager.create(AbstractBaseResourceManager.java:115) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.ResourceManagerRequestHandler.generate(ResourceManagerRequestHandler.java:40) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.AbstractResponseGenerator.handle(AbstractResponseGenerator.java:14) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.DefaultReadWriteApiDelegate.handle(DefaultReadWriteApiDelegate.java:27) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.DefaultReadWriteApiDelegate.write(DefaultReadWriteApiDelegate.java:22) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at sun.reflect.GeneratedMethodAccessor618.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_72]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_72]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) [spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:280) [spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) [spring-tx-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) [spring-aop-4.3.2.RELEASE.jar:4.3.2.RELEASE]
at com.sun.proxy.$Proxy73.write(Unknown Source) [na:na]
at io.github.ibuildthecloud.gdapi.request.handler.write.ReadWriteApiHandler.handle(ReadWriteApiHandler.java:19) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.github.ibuildthecloud.gdapi.servlet.ApiRequestFilterDelegate.doFilter(ApiRequestFilterDelegate.java:99) [cattle-framework-java-server-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.api.servlet.ApiRequestFilter$1.runInContext(ApiRequestFilter.java:96) [cattle-framework-api-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:55) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:108) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:52) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46) [cattle-framework-managed-context-0.5.0-SNAPSHOT.jar:na]
at io.cattle.platform.api.servlet.ApiRequestFilter.doFilter(ApiRequestFilter.java:106) [cattle-framework-api-0.5.0-SNAPSHOT.jar:na]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlets.UserAgentFilter.doFilter(UserAgentFilter.java:83) [jetty-servlets-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:300) [jetty-servlets-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) [jetty-security-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) [jetty-servlet-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.Server.handle(Server.java:499) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) [jetty-server-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) [jetty-util-9.2.11.v20150529.jar:9.2.11.v20150529]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) [jetty-util-9.2.11.v20150529.jar:9.2.11.v20150529]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_72]