Sean Roberts created AMBARI-25127:
-------------------------------------
Summary: ambari-server.log flooded if client not able to
authenticate through kerberos
Key: AMBARI-25127
URL: https://issues.apache.org/jira/browse/AMBARI-25127
Project: Ambari
Issue Type: Bug
Components: ambari-server
Affects Versions: 2.7.3
Reporter: Sean Roberts
With SPNEGO enabled for Ambari-Server, ambari-server.log is flooded with every
auth failure. _(See log output below)_.
This is making ambari-server.log impossible to review and fills rapidly.
REQUEST: ambari-server.log should not contain auth failures, especially not
full traces of them. JWT items should also likely be exluded from
ambari-server.log.
More detail:
- on every unauthenticated page load, Ambari makes the client attempt to auth
with Kerberos "negotiate".
- if that fails it falls back to other authentication mechanisms (user/pass
prompt or knoxsso).
- however, each of those failed auths results in this huge amount of logs in
`ambari-server`.log.
- for a failed or successful auth, the only log should be a single line in
`ambari-audit.log`
ambari-server.log: *1 second* from a single client on a new Ambari. Imagine
this on a busy ambari-server.
{code}
2019-01-24 04:46:02,749 INFO [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:265 - hadoop-jwt cookie has been found and is
being processed
2019-01-24 04:46:02,749 INFO [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:265 - hadoop-jwt cookie has been found and is
being processed
2019-01-24 04:46:02,750 INFO [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:265 - hadoop-jwt cookie has been found and is
being processed
2019-01-24 04:46:02,750 WARN [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:399 - JWT expiration date validation failed.
2019-01-24 04:46:02,750 INFO [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:294 - Expiration validation failed.
2019-01-24 04:46:02,750 WARN [ambari-client-thread-260388]
AmbariJwtAuthenticationFilter:201 - JWT authentication failed - Invalid JWT
token
2019-01-24 04:46:02,750 INFO [ambari-client-thread-260388]
AmbariAuthenticationEventHandlerImpl:136 - Failed to authenticate an unknown
user: Invalid JWT token
2019-01-24 04:46:02,756 WARN [ambari-client-thread-259406]
AmbariKerberosAuthenticationFilter:149 - Negotiate Header was invalid:
Negotiate TlRMTVNTUAABAAAAl4II4gAAAAAAAAAAAAAAAAAAAAAGAbEdAAAADw==
org.springframework.security.authentication.BadCredentialsException: Kerberos
validation not successful
at
org.springframework.security.kerberos.authentication.sun.SunJaasKerberosTicketValidator.validateTicket(SunJaasKerberosTicketValidator.java:71)
at
org.apache.ambari.server.security.authentication.kerberos.AmbariKerberosTicketValidator.validateTicket(AmbariKerberosTicketValidator.java:85)
at
org.apache.ambari.server.security.authentication.kerberos.AmbariKerberosAuthenticationProvider.authenticate(AmbariKerberosAuthenticationProvider.java:73)
at
org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:174)
at
org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:199)
at
org.springframework.security.config.annotation.web.configuration.WebSecurityConfigurerAdapter$AuthenticationManagerDelegator.authenticate(WebSecurityConfigurerAdapter.java:494)
at
org.springframework.security.kerberos.web.authentication.SpnegoAuthenticationProcessingFilter.doFilter(SpnegoAuthenticationProcessingFilter.java:145)
at
org.apache.ambari.server.security.authentication.kerberos.AmbariKerberosAuthenticationFilter.doFilter(AmbariKerberosAuthenticationFilter.java:179)
at
org.apache.ambari.server.security.authentication.AmbariDelegatingAuthenticationFilter.doFilter(AmbariDelegatingAuthenticationFilter.java:123)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.apache.ambari.server.security.authorization.AmbariUserAuthorizationFilter.doFilter(AmbariUserAuthorizationFilter.java:95)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:66)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
at
org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214)
at
org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177)
at
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)
at
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.apache.ambari.server.api.MethodOverrideFilter.doFilter(MethodOverrideFilter.java:73)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.apache.ambari.server.api.AmbariPersistFilter.doFilter(AmbariPersistFilter.java:53)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.apache.ambari.server.security.AbstractSecurityHeaderFilter.doFilter(AbstractSecurityHeaderFilter.java:130)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at org.eclipse.jetty.servlets.GzipFilter.doFilter(GzipFilter.java:51)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257)
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
at
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
at
org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:740)
at
org.apache.ambari.server.controller.AmbariHandlerList.processHandlers(AmbariHandlerList.java:221)
at
org.apache.ambari.server.controller.AmbariHandlerList.processHandlers(AmbariHandlerList.java:210)
at
org.apache.ambari.server.controller.AmbariHandlerList.handle(AmbariHandlerList.java:140)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
at org.eclipse.jetty.server.Server.handle(Server.java:503)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
at
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at
org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:411)
at
org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:305)
at
org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:159)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168)
at
org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126)
at
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.security.PrivilegedActionException: GSSException: Defective
token detected (Mechanism level: GSSHeader did not find the right tag)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at
org.springframework.security.kerberos.authentication.sun.SunJaasKerberosTicketValidator.validateTicket(SunJaasKerberosTicketValidator.java:68)
... 71 more
Caused by: GSSException: Defective token detected (Mechanism level: GSSHeader
did not find the right tag)
at sun.security.jgss.GSSHeader.<init>(GSSHeader.java:97)
at
sun.security.jgss.GSSContextImpl.acceptSecContext(GSSContextImpl.java:306)
at
sun.security.jgss.GSSContextImpl.acceptSecContext(GSSContextImpl.java:285)
at
org.springframework.security.kerberos.authentication.sun.SunJaasKerberosTicketValidator$KerberosValidateAction.run(SunJaasKerberosTicketValidator.java:170)
at
org.springframework.security.kerberos.authentication.sun.SunJaasKerberosTicketValidator$KerberosValidateAction.run(SunJaasKerberosTicketValidator.java:153)
... 74 more
2019-01-24 04:46:02,756 INFO [ambari-client-thread-259406]
AmbariAuthenticationEventHandlerImpl:136 - Failed to authenticate an unknown
user: Kerberos validation not successful
{code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
