[AMBARI-25127] ambari-server.log flooded if client not able to authenticate through kerberos - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Open
Priority: Major
Resolution: Unresolved
Affects Version/s: 2.7.3
Fix Version/s: None
Component/s: ambari-server
Labels:
None

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).

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

Attachments

Activity

People

Assignee:: amarnath reddy pappu

Reporter:: Sean Roberts

Votes:: 0 Vote for this issue

Watchers:: 3 Start watching this issue

Dates

Created:: 25/Jan/19 08:52

Updated:: 04/Apr/19 14:32