You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@ambari.apache.org by "Sean Roberts (JIRA)" <ji...@apache.org> on 2019/01/25 08:53:00 UTC
[jira] [Updated] (AMBARI-25127) ambari-server.log flooded if client
not able to authenticate through kerberos
[ https://issues.apache.org/jira/browse/AMBARI-25127?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sean Roberts updated AMBARI-25127:
----------------------------------
Description:
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 (scroll within the code block to see the big kerberos error).
{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}
was:
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}
> 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
> Priority: Major
>
> 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 (scroll within the code block to see the big kerberos error).
> {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)