You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@ranger.apache.org by Sailaja Polavarapu <sp...@cloudera.com> on 2020/12/02 01:30:06 UTC
Re: Ranger 2.1 - Usersync 401s after successful initial load
Hi Geri,
I haven't seen this issue in my local setup. From the above logs, I see
that "valid cookie is saved" after first sync, but in the next sync
cycle usersync is using credential login which is strange. In Usersync, for
every request to ranger admin, first try with the saved cookie (which is
the rangeradminsessionid). If it fails, then try with credentials. Can you
provide ranger admin logs to see - 1. why the session is invalid, 2. why
the rangerusersync creds login is failing.
Thanks,
Sailaja.
On Sat, Nov 28, 2020 at 5:45 PM Gergely Lendvai <ge...@gmail.com>
wrote:
> Hi!
>
> I am trying to solve this for a while, but with no luck so far. I managed
> to set up the usersync plugin with ldap (and without kerberos) and after
> starting it the initial users are showing up on Ranger, but all the
> upcoming hourly syncs are failing with the following error, which is a bit
> misleading since it is just a warning:
>
> -------------------------------------------------------------------------------------------------------------------------------
> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
> response from ranger is 401.
>
> -------------------------------------------------------------------------------------------------------------------------------
>
> I enabled debug logs to get a clearer picture, but what is odd that at the
> beginning my credentials are still valid and a new ranger cookie will be
> created for the initial sync, but for the next hour something happens. Here
> are the first couple of lines from the initial sync:
>
> -------------------------------------------------------------------------------------------------------------------------------
> INFO UserGroupSync [UnixUserSyncThread] - Begin: initial load of
> user/group from source==>sink
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> LdapDeltaUserGroupBuilder updateSink started
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
> search first
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> extendedUserSearchFilter =
> (&(objectclass=person)(|(uSNChanged>=0)(modifyTimestamp>=19700101000000Z)))
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
> 5564and currentDeltaSyncTime = 5564
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
> addPMAccount(awsadmind-906714de98)
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.getMUser()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
> ttributes":"{}"}
> INFO LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - valid cookie
> saved
>
> -------------------------------------------------------------------------------------------------------------------------------
>
> And these are the logs for an upcoming hour:
>
> -------------------------------------------------------------------------------------------------------------------------------
> INFO UserGroupSync [UnixUserSyncThread] - Begin: update user/group from
> source==>sink
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> LdapDeltaUserGroupBuilder updateSink started
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
> search first
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> extendedUserSearchFilter =
> (&(objectclass=person)(|(uSNChanged>=5631)(modifyTimestamp>=19700101000005Z)))
> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
> 5564and currentDeltaSyncTime = 5564
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
> addPMAccount(awsadmind-906714de98)
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.getMUser()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
> ttributes":"{}"}
> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
> response from ranger is 401.
>
> -------------------------------------------------------------------------------------------------------------------------------
>
> Could you help figure this out? I am happy to share more details if
> necessary.
>
> Thanks,
> Geri
>
Re: Ranger 2.1 - Usersync 401s after successful initial load
Posted by Sailaja Polavarapu <sp...@cloudera.com>.
Hi Geri,
In Ranger admin, for authentication, we first check if there is a valid
cookie. If not, then we try to authenticate using the configured
authentication method. If that fails, then we fall back to jdbc
authentication. For rangerusersync user, this is an internal user which is
created as part of ranger installation. So what you see for initial sync is
correct. We try to authenticate with ldap (which might be your configured
authentication method) and when failed, we fall back to jdbc authentication.
For the subsequent sync, I am not sure why the cookie is marked invalid.
One thing you can try is to disable usersync cookie based authentication by
setting "ranger.usersync.cookie.enabled" property to false in
ranger-ugsync-site.xml. This is to validate if ranger usersync username &
password are used properly for subsequent sync cycles.
Also, have you tried kerberos authentication for usersync?
- Sailaja.
On Wed, Dec 9, 2020 at 3:16 AM Gergely Lendvai <ge...@gmail.com>
wrote:
> Hi Sailaja,
>
> Did you have the chance to take a look at the logs?
>
> Cheers,
> Geri
>
>
> On Wed, Dec 2, 2020, 12:51 Gergely Lendvai <ge...@gmail.com>
> wrote:
>
>> Hi Sailaja,
>>
>> I could see this when the 401s happened, the cookie seems to be invalid
>> after the 1 hour wait since the first sync.
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 09:30:36,553 [http-bio-6080-Acceptor-0] DEBUG
>> org.apache.tomcat.util.threads.LimitLatch (LimitLatch.java:113) - Counting
>> up[http-bio-6080-Acceptor-0] latch=5
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.tomcat.util.http.Cookies (Cookies.java:184) - Cookies: Parsing
>> b[]:
>> $Version=1;RANGERADMINSESSIONID=5CEDC9023EA19CDA63F16A06345616F7;$Path=/
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.connector.CoyoteAdapter (CoyoteAdapter.java:1152) -
>> Requested cookie session id is 5CEDC9023EA19CDA63F16A06345616F7
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.authenticator.AuthenticatorBase
>> (AuthenticatorBase.java:458) - Security checking request POST
>> /service/users/default
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.realm.RealmBase (RealmBase.java:694) - No applicable
>> constraints defined
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.authenticator.AuthenticatorBase
>> (AuthenticatorBase.java:490) - Not subject to any constraint
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/login.jsp'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/styles/**'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/fonts/**'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/scripts/prelogin/XAPrelogin.js'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/libs/bower/jquery/js/jquery-3.5.1.js'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/images/ranger_logo.png'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/images/favicon.ico'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/policyList/*'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/resources/grant'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/resources/revoke'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/policies/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/services/grant/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/services/revoke/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/tags/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/roles/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/metrics/status'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 1 of 16 in
>> additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.SecurityContextPersistenceFilter
>> (SecurityContextPersistenceFilter.java:94) - Eagerly created session:
>> 48FDF9BA60D67FCEACE7C6C163398B08
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.HttpSessionSecurityContextRepository
>> (HttpSessionSecurityContextRepository.java:186) - HttpSession returned null
>> object for SPRING_SECURITY_CONTEXT
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.HttpSessionSecurityContextRepository
>> (HttpSessionSecurityContextRepository.java:116) - No SecurityContext was
>> available from the HttpSession:
>> org.apache.catalina.session.StandardSessionFacade@4ac271d4. A new one
>> will be created.
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 2 of 16 in
>> additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 3 of 16 in
>> additional filter chain; firing Filter: 'HeaderWriterFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 4 of 16 in
>> additional filter chain; firing Filter: 'LogoutFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/logout'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 5 of 16 in
>> additional filter chain; firing Filter:
>> 'RangerUsernamePasswordAuthenticationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/login'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 6 of 16 in
>> additional filter chain; firing Filter: 'BasicAuthenticationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 7 of 16 in
>> additional filter chain; firing Filter: 'RangerSSOAuthenticationFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 8 of 16 in
>> additional filter chain; firing Filter: 'RequestCacheAwareFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 9 of 16 in
>> additional filter chain; firing Filter:
>> 'SecurityContextHolderAwareRequestFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 10 of 16
>> in additional filter chain; firing Filter: 'RangerKRBAuthenticationFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 11 of 16
>> in additional filter chain; firing Filter: 'RangerCSRFPreventionFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 12 of 16
>> in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
>> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.authentication.AnonymousAuthenticationFilter
>> (AnonymousAuthenticationFilter.java:100) - Populated SecurityContextHolder
>> with anonymous token:
>> 'org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
>> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
>> Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
>> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
>> Granted Authorities: ROLE_ANONYMOUS'
>> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 13 of 16
>> in additional filter chain; firing Filter: 'SessionManagementFilter'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.session.SessionManagementFilter
>> (SessionManagementFilter.java:124) - Requested session ID
>> 5CEDC9023EA19CDA63F16A06345616F7 is invalid.
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 14 of 16
>> in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 15 of 16
>> in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor
>> (AbstractSecurityInterceptor.java:219) - Secure object: FilterInvocation:
>> URL: /service/users/default; Attributes: [isAuthenticated()]
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor
>> (AbstractSecurityInterceptor.java:348) - Previously Authenticated:
>> org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
>> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
>> Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
>> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
>> Granted Authorities: ROLE_ANONYMOUS
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.vote.AffirmativeBased
>> (AffirmativeBased.java:66) - Voter:
>> org.springframework.security.web.access.expression.WebExpressionVoter@46d48e8a,
>> returned: -1
>> 2020-12-02 09:30:36,562 [http-bio-6080-exec-18] DEBUG
>> org.springframework.context.support.ReloadableResourceBundleMessageSource
>> (ReloadableResourceBundleMessageSource.java:501) - Loading properties
>> [messages.properties]
>> 2020-12-02 09:30:36,563 [http-bio-6080-exec-18] DEBUG
>> org.springframework.context.support.ReloadableResourceBundleMessageSource
>> (ReloadableResourceBundleMessageSource.java:457) - No properties file found
>> for [WEB-INF/classes/internationalization/messages_en] - neither plain
>> properties nor XML
>> 2020-12-02 09:30:36,564 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.access.ExceptionTranslationFilter
>> (ExceptionTranslationFilter.java:173) - Access is denied (user is
>> anonymous); redirecting to authentication entry point
>> org.springframework.security.access.AccessDeniedException: Access is
>> denied
>> at
>> org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:84)
>> at
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:233)
>> at
>> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:124)
>> at
>> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter$ServletFilterHttpInteraction.proceed(RangerCSRFPreventionFilter.java:210)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.handleHttpInteraction(RangerCSRFPreventionFilter.java:155)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.doFilter(RangerCSRFPreventionFilter.java:165)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerKRBAuthenticationFilter.doFilter(RangerKRBAuthenticationFilter.java:399)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerSSOAuthenticationFilter.doFilter(RangerSSOAuthenticationFilter.java:259)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158)
>> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
>> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
>> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
>> at
>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
>> at
>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
>> at
>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
>> at
>> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
>> at
>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
>> at
>> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
>> at
>> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
>> at
>> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>> at java.lang.Thread.run(Thread.java:748)
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> I'm not sure why anonymousUser is used in this case instead of
>> rangerusersync. Before the initial sync I could see this:
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
>> org.springframework.security.ldap.authentication.BindAuthenticator
>> (BindAuthenticator.java:172) - Failed to bind as
>> cn=rangerusersync,cn=users,dc=corp,dc=prezi,dc=com:
>> org.springframework.ldap.AuthenticationException: [LDAP: error code 49 -
>> 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error,
>> data 52e, v1db1]; nested exception is javax.naming.AuthenticationException:
>> [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment:
>> AcceptSecurityContext error, data 52e, v1db1]
>> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
>> org.apache.ranger.security.handler.RangerAuthenticationProvider
>> (RangerAuthenticationProvider.java:262) - LDAP Authentication
>> Failed:org.springframework.security.authentication.BadCredentialsException:
>> Bad credentials
>> at
>> org.springframework.security.ldap.authentication.BindAuthenticator.authenticate(BindAuthenticator.java:101)
>> at
>> org.springframework.security.ldap.authentication.LdapAuthenticationProvider.doAuthentication(LdapAuthenticationProvider.java:187)
>> at
>> org.springframework.security.ldap.authentication.AbstractLdapAuthenticationProvider.authenticate(AbstractLdapAuthenticationProvider.java:85)
>> at
>> org.apache.ranger.security.handler.RangerAuthenticationProvider.getLdapAuthentication(RangerAuthenticationProvider.java:255)
>> at
>> org.apache.ranger.security.handler.RangerAuthenticationProvider.authenticate(RangerAuthenticationProvider.java:104)
>> at
>> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:174)
>> at
>> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:199)
>> at
>> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:180)
>> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
>> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
>> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
>> at
>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
>> at
>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
>> at
>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
>> at
>> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
>> at
>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
>> at
>> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
>> at
>> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
>> at
>> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>> at java.lang.Thread.run(Thread.java:748)
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Can this be because the user rangerusersync is not in ldap? Although in
>> spite of the error the initial sync was successful and I could see messages
>> like this later on:
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] INFO
>> org.apache.ranger.security.listener.SpringEventListener
>> (SpringEventListener.java:70) - Login Successful:rangerusersync | Ip
>> Address:127.0.0.1 | sessionId=5CEDC9023EA19CDA63F16A06345616F7 |
>> Epoch=1606897789058
>> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] DEBUG
>> springframework.security.web.authentication.www.BasicAuthenticationFilter
>> (BasicAuthenticationFilter.java:183) - Authentication success:
>> org.springframework.security.authentication.UsernamePasswordAuthenticationToken@836aa06d:
>> Principal: org.springframework.security.core.userdetails.User@826172bb:
>> Username: rangerusersync; Password: [PROTECTED]; Enabled: true;
>> AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked:
>> true; Granted Authorities: ROLE_SYS_ADMIN; Credentials: [PROTECTED];
>> Authenticated: true; Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@fffe3f86:
>> RemoteIpAddress: 127.0.0.1; SessionId: 5CEDC9023EA19CDA63F16A06345616F7;
>> Granted Authorities: ROLE_SYS_ADMIN
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Let me know if you need any further details.
>>
>> Thanks,
>> Geri
>>
>> Sailaja Polavarapu <sp...@cloudera.com> ezt írta (időpont: 2020.
>> dec. 2., Sze, 2:30):
>> >
>> > Hi Geri,
>> > I haven't seen this issue in my local setup. From the above logs, I
>> see that "valid cookie is saved" after first sync, but in the next sync
>> cycle usersync is using credential login which is strange. In Usersync, for
>> every request to ranger admin, first try with the saved cookie (which is
>> the rangeradminsessionid). If it fails, then try with credentials. Can you
>> provide ranger admin logs to see - 1. why the session is invalid, 2. why
>> the rangerusersync creds login is failing.
>> >
>> > Thanks,
>> > Sailaja.
>> >
>> > On Sat, Nov 28, 2020 at 5:45 PM Gergely Lendvai <
>> gergely.lendvai93@gmail.com> wrote:
>> >>
>> >> Hi!
>> >>
>> >> I am trying to solve this for a while, but with no luck so far. I
>> managed to set up the usersync plugin with ldap (and without kerberos) and
>> after starting it the initial users are showing up on Ranger, but all the
>> upcoming hourly syncs are failing with the following error, which is a bit
>> misleading since it is just a warning:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
>> response from ranger is 401.
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> I enabled debug logs to get a clearer picture, but what is odd that at
>> the beginning my credentials are still valid and a new ranger cookie will
>> be created for the initial sync, but for the next hour something happens.
>> Here are the first couple of lines from the initial sync:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: initial load of
>> user/group from source==>sink
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> LdapDeltaUserGroupBuilder updateSink started
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
>> search first
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> extendedUserSearchFilter =
>> (&(objectclass=person)(|(uSNChanged>=0)(modifyTimestamp>=19700101000000Z)))
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
>> 5564and currentDeltaSyncTime = 5564
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
>> addPMAccount(awsadmind-906714de98)
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.getMUser()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
>> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> >> ttributes":"{}"}
>> >> INFO LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - valid cookie
>> saved
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> And these are the logs for an upcoming hour:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: update user/group
>> from source==>sink
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> LdapDeltaUserGroupBuilder updateSink started
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
>> search first
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> extendedUserSearchFilter =
>> (&(objectclass=person)(|(uSNChanged>=5631)(modifyTimestamp>=19700101000005Z)))
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
>> 5564and currentDeltaSyncTime = 5564
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
>> addPMAccount(awsadmind-906714de98)
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.getMUser()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
>> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> >> ttributes":"{}"}
>> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
>> response from ranger is 401.
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> Could you help figure this out? I am happy to share more details if
>> necessary.
>> >>
>> >> Thanks,
>> >> Geri
>>
>>>
Re: Ranger 2.1 - Usersync 401s after successful initial load
Posted by Gergely Lendvai <ge...@gmail.com>.
Hi Sailaja,
I checked with the property disabled and now the hourly syncs are finishing
successfully, thanks so much for the recommendation. To also answer
your question I haven't tried kerberos with usersync so far.
Cheers,
Geri
Gergely Lendvai <ge...@gmail.com> ezt írta (időpont: 2020. dec.
9., Sze, 12:16):
> Hi Sailaja,
>
> Did you have the chance to take a look at the logs?
>
> Cheers,
> Geri
>
>
> On Wed, Dec 2, 2020, 12:51 Gergely Lendvai <ge...@gmail.com>
> wrote:
>
>> Hi Sailaja,
>>
>> I could see this when the 401s happened, the cookie seems to be invalid
>> after the 1 hour wait since the first sync.
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 09:30:36,553 [http-bio-6080-Acceptor-0] DEBUG
>> org.apache.tomcat.util.threads.LimitLatch (LimitLatch.java:113) - Counting
>> up[http-bio-6080-Acceptor-0] latch=5
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.tomcat.util.http.Cookies (Cookies.java:184) - Cookies: Parsing
>> b[]:
>> $Version=1;RANGERADMINSESSIONID=5CEDC9023EA19CDA63F16A06345616F7;$Path=/
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.connector.CoyoteAdapter (CoyoteAdapter.java:1152) -
>> Requested cookie session id is 5CEDC9023EA19CDA63F16A06345616F7
>> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.authenticator.AuthenticatorBase
>> (AuthenticatorBase.java:458) - Security checking request POST
>> /service/users/default
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.realm.RealmBase (RealmBase.java:694) - No applicable
>> constraints defined
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> org.apache.catalina.authenticator.AuthenticatorBase
>> (AuthenticatorBase.java:490) - Not subject to any constraint
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/login.jsp'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/styles/**'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/fonts/**'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/scripts/prelogin/XAPrelogin.js'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/libs/bower/jquery/js/jquery-3.5.1.js'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/images/ranger_logo.png'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/images/favicon.ico'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/policyList/*'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/resources/grant'
>> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/assets/resources/revoke'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/policies/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/services/grant/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/plugins/services/revoke/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/tags/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/roles/download/*'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/service/metrics/status'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 1 of 16 in
>> additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.SecurityContextPersistenceFilter
>> (SecurityContextPersistenceFilter.java:94) - Eagerly created session:
>> 48FDF9BA60D67FCEACE7C6C163398B08
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.HttpSessionSecurityContextRepository
>> (HttpSessionSecurityContextRepository.java:186) - HttpSession returned null
>> object for SPRING_SECURITY_CONTEXT
>> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.context.HttpSessionSecurityContextRepository
>> (HttpSessionSecurityContextRepository.java:116) - No SecurityContext was
>> available from the HttpSession:
>> org.apache.catalina.session.StandardSessionFacade@4ac271d4. A new one
>> will be created.
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 2 of 16 in
>> additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 3 of 16 in
>> additional filter chain; firing Filter: 'HeaderWriterFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 4 of 16 in
>> additional filter chain; firing Filter: 'LogoutFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/logout'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 5 of 16 in
>> additional filter chain; firing Filter:
>> 'RangerUsernamePasswordAuthenticationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> springframework.security.web.util.matcher.AntPathRequestMatcher
>> (AntPathRequestMatcher.java:176) - Checking match of request :
>> '/service/users/default'; against '/login'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 6 of 16 in
>> additional filter chain; firing Filter: 'BasicAuthenticationFilter'
>> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 7 of 16 in
>> additional filter chain; firing Filter: 'RangerSSOAuthenticationFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 8 of 16 in
>> additional filter chain; firing Filter: 'RequestCacheAwareFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 9 of 16 in
>> additional filter chain; firing Filter:
>> 'SecurityContextHolderAwareRequestFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 10 of 16
>> in additional filter chain; firing Filter: 'RangerKRBAuthenticationFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 11 of 16
>> in additional filter chain; firing Filter: 'RangerCSRFPreventionFilter'
>> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 12 of 16
>> in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
>> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.authentication.AnonymousAuthenticationFilter
>> (AnonymousAuthenticationFilter.java:100) - Populated SecurityContextHolder
>> with anonymous token:
>> 'org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
>> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
>> Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
>> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
>> Granted Authorities: ROLE_ANONYMOUS'
>> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 13 of 16
>> in additional filter chain; firing Filter: 'SessionManagementFilter'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.session.SessionManagementFilter
>> (SessionManagementFilter.java:124) - Requested session ID
>> 5CEDC9023EA19CDA63F16A06345616F7 is invalid.
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 14 of 16
>> in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
>> (FilterChainProxy.java:325) - /service/users/default at position 15 of 16
>> in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor
>> (AbstractSecurityInterceptor.java:219) - Secure object: FilterInvocation:
>> URL: /service/users/default; Attributes: [isAuthenticated()]
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor
>> (AbstractSecurityInterceptor.java:348) - Previously Authenticated:
>> org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
>> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
>> Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
>> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
>> Granted Authorities: ROLE_ANONYMOUS
>> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.access.vote.AffirmativeBased
>> (AffirmativeBased.java:66) - Voter:
>> org.springframework.security.web.access.expression.WebExpressionVoter@46d48e8a,
>> returned: -1
>> 2020-12-02 09:30:36,562 [http-bio-6080-exec-18] DEBUG
>> org.springframework.context.support.ReloadableResourceBundleMessageSource
>> (ReloadableResourceBundleMessageSource.java:501) - Loading properties
>> [messages.properties]
>> 2020-12-02 09:30:36,563 [http-bio-6080-exec-18] DEBUG
>> org.springframework.context.support.ReloadableResourceBundleMessageSource
>> (ReloadableResourceBundleMessageSource.java:457) - No properties file found
>> for [WEB-INF/classes/internationalization/messages_en] - neither plain
>> properties nor XML
>> 2020-12-02 09:30:36,564 [http-bio-6080-exec-18] DEBUG
>> org.springframework.security.web.access.ExceptionTranslationFilter
>> (ExceptionTranslationFilter.java:173) - Access is denied (user is
>> anonymous); redirecting to authentication entry point
>> org.springframework.security.access.AccessDeniedException: Access is
>> denied
>> at
>> org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:84)
>> at
>> org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:233)
>> at
>> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:124)
>> at
>> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter$ServletFilterHttpInteraction.proceed(RangerCSRFPreventionFilter.java:210)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.handleHttpInteraction(RangerCSRFPreventionFilter.java:155)
>> at
>> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.doFilter(RangerCSRFPreventionFilter.java:165)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerKRBAuthenticationFilter.doFilter(RangerKRBAuthenticationFilter.java:399)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.apache.ranger.security.web.filter.RangerSSOAuthenticationFilter.doFilter(RangerSSOAuthenticationFilter.java:259)
>> at
>> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
>> at
>> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158)
>> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
>> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
>> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
>> at
>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
>> at
>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
>> at
>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
>> at
>> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
>> at
>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
>> at
>> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
>> at
>> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
>> at
>> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>> at java.lang.Thread.run(Thread.java:748)
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> I'm not sure why anonymousUser is used in this case instead of
>> rangerusersync. Before the initial sync I could see this:
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
>> org.springframework.security.ldap.authentication.BindAuthenticator
>> (BindAuthenticator.java:172) - Failed to bind as
>> cn=rangerusersync,cn=users,dc=corp,dc=prezi,dc=com:
>> org.springframework.ldap.AuthenticationException: [LDAP: error code 49 -
>> 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error,
>> data 52e, v1db1]; nested exception is javax.naming.AuthenticationException:
>> [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment:
>> AcceptSecurityContext error, data 52e, v1db1]
>> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
>> org.apache.ranger.security.handler.RangerAuthenticationProvider
>> (RangerAuthenticationProvider.java:262) - LDAP Authentication
>> Failed:org.springframework.security.authentication.BadCredentialsException:
>> Bad credentials
>> at
>> org.springframework.security.ldap.authentication.BindAuthenticator.authenticate(BindAuthenticator.java:101)
>> at
>> org.springframework.security.ldap.authentication.LdapAuthenticationProvider.doAuthentication(LdapAuthenticationProvider.java:187)
>> at
>> org.springframework.security.ldap.authentication.AbstractLdapAuthenticationProvider.authenticate(AbstractLdapAuthenticationProvider.java:85)
>> at
>> org.apache.ranger.security.handler.RangerAuthenticationProvider.getLdapAuthentication(RangerAuthenticationProvider.java:255)
>> at
>> org.apache.ranger.security.handler.RangerAuthenticationProvider.authenticate(RangerAuthenticationProvider.java:104)
>> at
>> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:174)
>> at
>> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:199)
>> at
>> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:180)
>> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
>> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
>> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
>> at
>> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
>> at
>> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
>> at
>> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
>> at
>> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
>> at
>> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
>> at
>> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
>> at
>> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
>> at
>> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
>> at
>> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
>> at
>> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
>> at
>> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
>> at
>> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
>> at
>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
>> at
>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
>> at
>> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
>> at java.lang.Thread.run(Thread.java:748)
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Can this be because the user rangerusersync is not in ldap? Although in
>> spite of the error the initial sync was successful and I could see messages
>> like this later on:
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] INFO
>> org.apache.ranger.security.listener.SpringEventListener
>> (SpringEventListener.java:70) - Login Successful:rangerusersync | Ip
>> Address:127.0.0.1 | sessionId=5CEDC9023EA19CDA63F16A06345616F7 |
>> Epoch=1606897789058
>> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] DEBUG
>> springframework.security.web.authentication.www.BasicAuthenticationFilter
>> (BasicAuthenticationFilter.java:183) - Authentication success:
>> org.springframework.security.authentication.UsernamePasswordAuthenticationToken@836aa06d:
>> Principal: org.springframework.security.core.userdetails.User@826172bb:
>> Username: rangerusersync; Password: [PROTECTED]; Enabled: true;
>> AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked:
>> true; Granted Authorities: ROLE_SYS_ADMIN; Credentials: [PROTECTED];
>> Authenticated: true; Details:
>> org.springframework.security.web.authentication.WebAuthenticationDetails@fffe3f86:
>> RemoteIpAddress: 127.0.0.1; SessionId: 5CEDC9023EA19CDA63F16A06345616F7;
>> Granted Authorities: ROLE_SYS_ADMIN
>>
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Let me know if you need any further details.
>>
>> Thanks,
>> Geri
>>
>> Sailaja Polavarapu <sp...@cloudera.com> ezt írta (időpont: 2020.
>> dec. 2., Sze, 2:30):
>> >
>> > Hi Geri,
>> > I haven't seen this issue in my local setup. From the above logs, I
>> see that "valid cookie is saved" after first sync, but in the next sync
>> cycle usersync is using credential login which is strange. In Usersync, for
>> every request to ranger admin, first try with the saved cookie (which is
>> the rangeradminsessionid). If it fails, then try with credentials. Can you
>> provide ranger admin logs to see - 1. why the session is invalid, 2. why
>> the rangerusersync creds login is failing.
>> >
>> > Thanks,
>> > Sailaja.
>> >
>> > On Sat, Nov 28, 2020 at 5:45 PM Gergely Lendvai <
>> gergely.lendvai93@gmail.com> wrote:
>> >>
>> >> Hi!
>> >>
>> >> I am trying to solve this for a while, but with no luck so far. I
>> managed to set up the usersync plugin with ldap (and without kerberos) and
>> after starting it the initial users are showing up on Ranger, but all the
>> upcoming hourly syncs are failing with the following error, which is a bit
>> misleading since it is just a warning:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
>> response from ranger is 401.
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> I enabled debug logs to get a clearer picture, but what is odd that at
>> the beginning my credentials are still valid and a new ranger cookie will
>> be created for the initial sync, but for the next hour something happens.
>> Here are the first couple of lines from the initial sync:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: initial load of
>> user/group from source==>sink
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> LdapDeltaUserGroupBuilder updateSink started
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
>> search first
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> extendedUserSearchFilter =
>> (&(objectclass=person)(|(uSNChanged>=0)(modifyTimestamp>=19700101000000Z)))
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
>> 5564and currentDeltaSyncTime = 5564
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
>> addPMAccount(awsadmind-906714de98)
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.getMUser()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
>> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> >> ttributes":"{}"}
>> >> INFO LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - valid cookie
>> saved
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> And these are the logs for an upcoming hour:
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: update user/group
>> from source==>sink
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> LdapDeltaUserGroupBuilder updateSink started
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
>> search first
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
>> extendedUserSearchFilter =
>> (&(objectclass=person)(|(uSNChanged>=5631)(modifyTimestamp>=19700101000005Z)))
>> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
>> 5564and currentDeltaSyncTime = 5564
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
>> addPMAccount(awsadmind-906714de98)
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.getMUser()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
>> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
>> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> >> ttributes":"{}"}
>> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
>> response from ranger is 401.
>> >>
>> -------------------------------------------------------------------------------------------------------------------------------
>> >>
>> >> Could you help figure this out? I am happy to share more details if
>> necessary.
>> >>
>> >> Thanks,
>> >> Geri
>>
>>>
Re: Ranger 2.1 - Usersync 401s after successful initial load
Posted by Gergely Lendvai <ge...@gmail.com>.
Hi Sailaja,
Did you have the chance to take a look at the logs?
Cheers,
Geri
On Wed, Dec 2, 2020, 12:51 Gergely Lendvai <ge...@gmail.com>
wrote:
> Hi Sailaja,
>
> I could see this when the 401s happened, the cookie seems to be invalid
> after the 1 hour wait since the first sync.
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> 2020-12-02 09:30:36,553 [http-bio-6080-Acceptor-0] DEBUG
> org.apache.tomcat.util.threads.LimitLatch (LimitLatch.java:113) - Counting
> up[http-bio-6080-Acceptor-0] latch=5
> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
> org.apache.tomcat.util.http.Cookies (Cookies.java:184) - Cookies: Parsing
> b[]:
> $Version=1;RANGERADMINSESSIONID=5CEDC9023EA19CDA63F16A06345616F7;$Path=/
> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
> org.apache.catalina.connector.CoyoteAdapter (CoyoteAdapter.java:1152) -
> Requested cookie session id is 5CEDC9023EA19CDA63F16A06345616F7
> 2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
> org.apache.catalina.authenticator.AuthenticatorBase
> (AuthenticatorBase.java:458) - Security checking request POST
> /service/users/default
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> org.apache.catalina.realm.RealmBase (RealmBase.java:694) - No applicable
> constraints defined
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> org.apache.catalina.authenticator.AuthenticatorBase
> (AuthenticatorBase.java:490) - Not subject to any constraint
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/login.jsp'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/styles/**'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/fonts/**'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/scripts/prelogin/XAPrelogin.js'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/libs/bower/jquery/js/jquery-3.5.1.js'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/images/ranger_logo.png'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/images/favicon.ico'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/assets/policyList/*'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/assets/resources/grant'
> 2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/assets/resources/revoke'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/plugins/policies/download/*'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/plugins/services/grant/*'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/plugins/services/revoke/*'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/tags/download/*'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/roles/download/*'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/service/metrics/status'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 1 of 16 in
> additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.context.SecurityContextPersistenceFilter
> (SecurityContextPersistenceFilter.java:94) - Eagerly created session:
> 48FDF9BA60D67FCEACE7C6C163398B08
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.context.HttpSessionSecurityContextRepository
> (HttpSessionSecurityContextRepository.java:186) - HttpSession returned null
> object for SPRING_SECURITY_CONTEXT
> 2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.context.HttpSessionSecurityContextRepository
> (HttpSessionSecurityContextRepository.java:116) - No SecurityContext was
> available from the HttpSession:
> org.apache.catalina.session.StandardSessionFacade@4ac271d4. A new one
> will be created.
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 2 of 16 in
> additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 3 of 16 in
> additional filter chain; firing Filter: 'HeaderWriterFilter'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 4 of 16 in
> additional filter chain; firing Filter: 'LogoutFilter'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/logout'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 5 of 16 in
> additional filter chain; firing Filter:
> 'RangerUsernamePasswordAuthenticationFilter'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> springframework.security.web.util.matcher.AntPathRequestMatcher
> (AntPathRequestMatcher.java:176) - Checking match of request :
> '/service/users/default'; against '/login'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 6 of 16 in
> additional filter chain; firing Filter: 'BasicAuthenticationFilter'
> 2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 7 of 16 in
> additional filter chain; firing Filter: 'RangerSSOAuthenticationFilter'
> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 8 of 16 in
> additional filter chain; firing Filter: 'RequestCacheAwareFilter'
> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 9 of 16 in
> additional filter chain; firing Filter:
> 'SecurityContextHolderAwareRequestFilter'
> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 10 of 16
> in additional filter chain; firing Filter: 'RangerKRBAuthenticationFilter'
> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 11 of 16
> in additional filter chain; firing Filter: 'RangerCSRFPreventionFilter'
> 2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 12 of 16
> in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.authentication.AnonymousAuthenticationFilter
> (AnonymousAuthenticationFilter.java:100) - Populated SecurityContextHolder
> with anonymous token:
> 'org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
> Details:
> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
> Granted Authorities: ROLE_ANONYMOUS'
> 2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 13 of 16
> in additional filter chain; firing Filter: 'SessionManagementFilter'
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.session.SessionManagementFilter
> (SessionManagementFilter.java:124) - Requested session ID
> 5CEDC9023EA19CDA63F16A06345616F7 is invalid.
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 14 of 16
> in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain
> (FilterChainProxy.java:325) - /service/users/default at position 15 of 16
> in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.access.intercept.AbstractSecurityInterceptor
> (AbstractSecurityInterceptor.java:219) - Secure object: FilterInvocation:
> URL: /service/users/default; Attributes: [isAuthenticated()]
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.access.intercept.AbstractSecurityInterceptor
> (AbstractSecurityInterceptor.java:348) - Previously Authenticated:
> org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
> Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
> Details:
> org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
> RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
> Granted Authorities: ROLE_ANONYMOUS
> 2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.access.vote.AffirmativeBased
> (AffirmativeBased.java:66) - Voter:
> org.springframework.security.web.access.expression.WebExpressionVoter@46d48e8a,
> returned: -1
> 2020-12-02 09:30:36,562 [http-bio-6080-exec-18] DEBUG
> org.springframework.context.support.ReloadableResourceBundleMessageSource
> (ReloadableResourceBundleMessageSource.java:501) - Loading properties
> [messages.properties]
> 2020-12-02 09:30:36,563 [http-bio-6080-exec-18] DEBUG
> org.springframework.context.support.ReloadableResourceBundleMessageSource
> (ReloadableResourceBundleMessageSource.java:457) - No properties file found
> for [WEB-INF/classes/internationalization/messages_en] - neither plain
> properties nor XML
> 2020-12-02 09:30:36,564 [http-bio-6080-exec-18] DEBUG
> org.springframework.security.web.access.ExceptionTranslationFilter
> (ExceptionTranslationFilter.java:173) - Access is denied (user is
> anonymous); redirecting to authentication entry point
> org.springframework.security.access.AccessDeniedException: Access is denied
> at
> org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:84)
> at
> org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:233)
> at
> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:124)
> at
> org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter$ServletFilterHttpInteraction.proceed(RangerCSRFPreventionFilter.java:210)
> at
> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.handleHttpInteraction(RangerCSRFPreventionFilter.java:155)
> at
> org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.doFilter(RangerCSRFPreventionFilter.java:165)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.apache.ranger.security.web.filter.RangerKRBAuthenticationFilter.doFilter(RangerKRBAuthenticationFilter.java:399)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.apache.ranger.security.web.filter.RangerSSOAuthenticationFilter.doFilter(RangerSSOAuthenticationFilter.java:259)
> at
> org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
> at
> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158)
> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
> at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
> at
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
> at
> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
> at
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
> at
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
> at
> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
> at
> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
> at
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
> at
> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
> at
> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
> at
> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> at java.lang.Thread.run(Thread.java:748)
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> I'm not sure why anonymousUser is used in this case instead of
> rangerusersync. Before the initial sync I could see this:
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
> org.springframework.security.ldap.authentication.BindAuthenticator
> (BindAuthenticator.java:172) - Failed to bind as
> cn=rangerusersync,cn=users,dc=corp,dc=prezi,dc=com:
> org.springframework.ldap.AuthenticationException: [LDAP: error code 49 -
> 80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error,
> data 52e, v1db1]; nested exception is javax.naming.AuthenticationException:
> [LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment:
> AcceptSecurityContext error, data 52e, v1db1]
> 2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
> org.apache.ranger.security.handler.RangerAuthenticationProvider
> (RangerAuthenticationProvider.java:262) - LDAP Authentication
> Failed:org.springframework.security.authentication.BadCredentialsException:
> Bad credentials
> at
> org.springframework.security.ldap.authentication.BindAuthenticator.authenticate(BindAuthenticator.java:101)
> at
> org.springframework.security.ldap.authentication.LdapAuthenticationProvider.doAuthentication(LdapAuthenticationProvider.java:187)
> at
> org.springframework.security.ldap.authentication.AbstractLdapAuthenticationProvider.authenticate(AbstractLdapAuthenticationProvider.java:85)
> at
> org.apache.ranger.security.handler.RangerAuthenticationProvider.getLdapAuthentication(RangerAuthenticationProvider.java:255)
> at
> org.apache.ranger.security.handler.RangerAuthenticationProvider.authenticate(RangerAuthenticationProvider.java:104)
> at
> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:174)
> at
> org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:199)
> at
> org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:180)
> 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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
> 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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
> 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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
> at
> org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
> at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
> at
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
> at
> org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
> at
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
> at
> org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
> at
> org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
> at
> org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
> at
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
> at
> org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
> at
> org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
> at
> org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at
> org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> at java.lang.Thread.run(Thread.java:748)
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Can this be because the user rangerusersync is not in ldap? Although in
> spite of the error the initial sync was successful and I could see messages
> like this later on:
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] INFO
> org.apache.ranger.security.listener.SpringEventListener
> (SpringEventListener.java:70) - Login Successful:rangerusersync | Ip
> Address:127.0.0.1 | sessionId=5CEDC9023EA19CDA63F16A06345616F7 |
> Epoch=1606897789058
> 2020-12-02 08:29:49,058 [http-bio-6080-exec-7] DEBUG
> springframework.security.web.authentication.www.BasicAuthenticationFilter
> (BasicAuthenticationFilter.java:183) - Authentication success:
> org.springframework.security.authentication.UsernamePasswordAuthenticationToken@836aa06d:
> Principal: org.springframework.security.core.userdetails.User@826172bb:
> Username: rangerusersync; Password: [PROTECTED]; Enabled: true;
> AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked:
> true; Granted Authorities: ROLE_SYS_ADMIN; Credentials: [PROTECTED];
> Authenticated: true; Details:
> org.springframework.security.web.authentication.WebAuthenticationDetails@fffe3f86:
> RemoteIpAddress: 127.0.0.1; SessionId: 5CEDC9023EA19CDA63F16A06345616F7;
> Granted Authorities: ROLE_SYS_ADMIN
>
> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
> Let me know if you need any further details.
>
> Thanks,
> Geri
>
> Sailaja Polavarapu <sp...@cloudera.com> ezt írta (időpont: 2020.
> dec. 2., Sze, 2:30):
> >
> > Hi Geri,
> > I haven't seen this issue in my local setup. From the above logs, I see
> that "valid cookie is saved" after first sync, but in the next sync cycle
> usersync is using credential login which is strange. In Usersync, for every
> request to ranger admin, first try with the saved cookie (which is the
> rangeradminsessionid). If it fails, then try with credentials. Can you
> provide ranger admin logs to see - 1. why the session is invalid, 2. why
> the rangerusersync creds login is failing.
> >
> > Thanks,
> > Sailaja.
> >
> > On Sat, Nov 28, 2020 at 5:45 PM Gergely Lendvai <
> gergely.lendvai93@gmail.com> wrote:
> >>
> >> Hi!
> >>
> >> I am trying to solve this for a while, but with no luck so far. I
> managed to set up the usersync plugin with ldap (and without kerberos) and
> after starting it the initial users are showing up on Ranger, but all the
> upcoming hourly syncs are failing with the following error, which is a bit
> misleading since it is just a warning:
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
> response from ranger is 401.
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >>
> >> I enabled debug logs to get a clearer picture, but what is odd that at
> the beginning my credentials are still valid and a new ranger cookie will
> be created for the initial sync, but for the next hour something happens.
> Here are the first couple of lines from the initial sync:
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: initial load of
> user/group from source==>sink
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> LdapDeltaUserGroupBuilder updateSink started
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
> search first
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> extendedUserSearchFilter =
> (&(objectclass=person)(|(uSNChanged>=0)(modifyTimestamp>=19700101000000Z)))
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
> 5564and currentDeltaSyncTime = 5564
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
> addPMAccount(awsadmind-906714de98)
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.getMUser()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
> >> ttributes":"{}"}
> >> INFO LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - valid cookie
> saved
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >>
> >> And these are the logs for an upcoming hour:
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >> INFO UserGroupSync [UnixUserSyncThread] - Begin: update user/group from
> source==>sink
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> LdapDeltaUserGroupBuilder updateSink started
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
> search first
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
> extendedUserSearchFilter =
> (&(objectclass=person)(|(uSNChanged>=5631)(modifyTimestamp>=19700101000005Z)))
> >> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
> 5564and currentDeltaSyncTime = 5564
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
> addPMAccount(awsadmind-906714de98)
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.getMUser()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
> LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
> >> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
> MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
> >> ttributes":"{}"}
> >> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
> response from ranger is 401.
> >>
> -------------------------------------------------------------------------------------------------------------------------------
> >>
> >> Could you help figure this out? I am happy to share more details if
> necessary.
> >>
> >> Thanks,
> >> Geri
>
>>
Re: Ranger 2.1 - Usersync 401s after successful initial load
Posted by Gergely Lendvai <ge...@gmail.com>.
Hi Sailaja,
I could see this when the 401s happened, the cookie seems to be invalid
after the 1 hour wait since the first sync.
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2020-12-02 09:30:36,553 [http-bio-6080-Acceptor-0] DEBUG
org.apache.tomcat.util.threads.LimitLatch (LimitLatch.java:113) - Counting
up[http-bio-6080-Acceptor-0] latch=5
2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
org.apache.tomcat.util.http.Cookies (Cookies.java:184) - Cookies: Parsing
b[]:
$Version=1;RANGERADMINSESSIONID=5CEDC9023EA19CDA63F16A06345616F7;$Path=/
2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
org.apache.catalina.connector.CoyoteAdapter (CoyoteAdapter.java:1152) -
Requested cookie session id is 5CEDC9023EA19CDA63F16A06345616F7
2020-12-02 09:30:36,554 [http-bio-6080-exec-18] DEBUG
org.apache.catalina.authenticator.AuthenticatorBase
(AuthenticatorBase.java:458) - Security checking request POST
/service/users/default
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
org.apache.catalina.realm.RealmBase (RealmBase.java:694) - No applicable
constraints defined
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
org.apache.catalina.authenticator.AuthenticatorBase
(AuthenticatorBase.java:490) - Not subject to any constraint
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/login.jsp'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/styles/**'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/fonts/**'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/scripts/prelogin/XAPrelogin.js'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/libs/bower/jquery/js/jquery-3.5.1.js'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/images/ranger_logo.png'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/images/favicon.ico'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/assets/policyList/*'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/assets/resources/grant'
2020-12-02 09:30:36,555 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/assets/resources/revoke'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/plugins/policies/download/*'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/plugins/services/grant/*'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/plugins/services/revoke/*'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/tags/download/*'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/roles/download/*'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/service/metrics/status'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 1 of 16 in
additional filter chain; firing Filter: 'SecurityContextPersistenceFilter'
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.context.SecurityContextPersistenceFilter
(SecurityContextPersistenceFilter.java:94) - Eagerly created session:
48FDF9BA60D67FCEACE7C6C163398B08
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.context.HttpSessionSecurityContextRepository
(HttpSessionSecurityContextRepository.java:186) - HttpSession returned null
object for SPRING_SECURITY_CONTEXT
2020-12-02 09:30:36,556 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.context.HttpSessionSecurityContextRepository
(HttpSessionSecurityContextRepository.java:116) - No SecurityContext was
available from the HttpSession:
org.apache.catalina.session.StandardSessionFacade@4ac271d4. A new one will
be created.
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 2 of 16 in
additional filter chain; firing Filter: 'WebAsyncManagerIntegrationFilter'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 3 of 16 in
additional filter chain; firing Filter: 'HeaderWriterFilter'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 4 of 16 in
additional filter chain; firing Filter: 'LogoutFilter'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/logout'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 5 of 16 in
additional filter chain; firing Filter:
'RangerUsernamePasswordAuthenticationFilter'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
springframework.security.web.util.matcher.AntPathRequestMatcher
(AntPathRequestMatcher.java:176) - Checking match of request :
'/service/users/default'; against '/login'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 6 of 16 in
additional filter chain; firing Filter: 'BasicAuthenticationFilter'
2020-12-02 09:30:36,557 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 7 of 16 in
additional filter chain; firing Filter: 'RangerSSOAuthenticationFilter'
2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 8 of 16 in
additional filter chain; firing Filter: 'RequestCacheAwareFilter'
2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 9 of 16 in
additional filter chain; firing Filter:
'SecurityContextHolderAwareRequestFilter'
2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 10 of 16
in additional filter chain; firing Filter: 'RangerKRBAuthenticationFilter'
2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 11 of 16
in additional filter chain; firing Filter: 'RangerCSRFPreventionFilter'
2020-12-02 09:30:36,558 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 12 of 16
in additional filter chain; firing Filter: 'AnonymousAuthenticationFilter'
2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.authentication.AnonymousAuthenticationFilter
(AnonymousAuthenticationFilter.java:100) - Populated SecurityContextHolder
with anonymous token:
'org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
Details:
org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
Granted Authorities: ROLE_ANONYMOUS'
2020-12-02 09:30:36,560 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 13 of 16
in additional filter chain; firing Filter: 'SessionManagementFilter'
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.session.SessionManagementFilter
(SessionManagementFilter.java:124) - Requested session ID
5CEDC9023EA19CDA63F16A06345616F7 is invalid.
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 14 of 16
in additional filter chain; firing Filter: 'ExceptionTranslationFilter'
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.FilterChainProxy$VirtualFilterChain
(FilterChainProxy.java:325) - /service/users/default at position 15 of 16
in additional filter chain; firing Filter: 'FilterSecurityInterceptor'
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.access.intercept.AbstractSecurityInterceptor
(AbstractSecurityInterceptor.java:219) - Secure object: FilterInvocation:
URL: /service/users/default; Attributes: [isAuthenticated()]
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.access.intercept.AbstractSecurityInterceptor
(AbstractSecurityInterceptor.java:348) - Previously Authenticated:
org.springframework.security.authentication.AnonymousAuthenticationToken@90579aae:
Principal: anonymousUser; Credentials: [PROTECTED]; Authenticated: true;
Details:
org.springframework.security.web.authentication.WebAuthenticationDetails@2eb76:
RemoteIpAddress: 127.0.0.1; SessionId: 48FDF9BA60D67FCEACE7C6C163398B08;
Granted Authorities: ROLE_ANONYMOUS
2020-12-02 09:30:36,561 [http-bio-6080-exec-18] DEBUG
org.springframework.security.access.vote.AffirmativeBased
(AffirmativeBased.java:66) - Voter:
org.springframework.security.web.access.expression.WebExpressionVoter@46d48e8a,
returned: -1
2020-12-02 09:30:36,562 [http-bio-6080-exec-18] DEBUG
org.springframework.context.support.ReloadableResourceBundleMessageSource
(ReloadableResourceBundleMessageSource.java:501) - Loading properties
[messages.properties]
2020-12-02 09:30:36,563 [http-bio-6080-exec-18] DEBUG
org.springframework.context.support.ReloadableResourceBundleMessageSource
(ReloadableResourceBundleMessageSource.java:457) - No properties file found
for [WEB-INF/classes/internationalization/messages_en] - neither plain
properties nor XML
2020-12-02 09:30:36,564 [http-bio-6080-exec-18] DEBUG
org.springframework.security.web.access.ExceptionTranslationFilter
(ExceptionTranslationFilter.java:173) - Access is denied (user is
anonymous); redirecting to authentication entry point
org.springframework.security.access.AccessDeniedException: Access is denied
at
org.springframework.security.access.vote.AffirmativeBased.decide(AffirmativeBased.java:84)
at
org.springframework.security.access.intercept.AbstractSecurityInterceptor.beforeInvocation(AbstractSecurityInterceptor.java:233)
at
org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:124)
at
org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter$ServletFilterHttpInteraction.proceed(RangerCSRFPreventionFilter.java:210)
at
org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.handleHttpInteraction(RangerCSRFPreventionFilter.java:155)
at
org.apache.ranger.security.web.filter.RangerCSRFPreventionFilter.doFilter(RangerCSRFPreventionFilter.java:165)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.apache.ranger.security.web.filter.RangerKRBAuthenticationFilter.doFilter(RangerKRBAuthenticationFilter.java:399)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.apache.ranger.security.web.filter.RangerSSOAuthenticationFilter.doFilter(RangerSSOAuthenticationFilter.java:259)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
at
org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:158)
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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
I'm not sure why anonymousUser is used in this case instead of
rangerusersync. Before the initial sync I could see this:
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
org.springframework.security.ldap.authentication.BindAuthenticator
(BindAuthenticator.java:172) - Failed to bind as
cn=rangerusersync,cn=users,dc=corp,dc=prezi,dc=com:
org.springframework.ldap.AuthenticationException: [LDAP: error code 49 -
80090308: LdapErr: DSID-0C0903A9, comment: AcceptSecurityContext error,
data 52e, v1db1]; nested exception is javax.naming.AuthenticationException:
[LDAP: error code 49 - 80090308: LdapErr: DSID-0C0903A9, comment:
AcceptSecurityContext error, data 52e, v1db1]
2020-12-02 08:29:48,769 [http-bio-6080-exec-7] DEBUG
org.apache.ranger.security.handler.RangerAuthenticationProvider
(RangerAuthenticationProvider.java:262) - LDAP Authentication
Failed:org.springframework.security.authentication.BadCredentialsException:
Bad credentials
at
org.springframework.security.ldap.authentication.BindAuthenticator.authenticate(BindAuthenticator.java:101)
at
org.springframework.security.ldap.authentication.LdapAuthenticationProvider.doAuthentication(LdapAuthenticationProvider.java:187)
at
org.springframework.security.ldap.authentication.AbstractLdapAuthenticationProvider.authenticate(AbstractLdapAuthenticationProvider.java:85)
at
org.apache.ranger.security.handler.RangerAuthenticationProvider.getLdapAuthentication(RangerAuthenticationProvider.java:255)
at
org.apache.ranger.security.handler.RangerAuthenticationProvider.authenticate(RangerAuthenticationProvider.java:104)
at
org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:174)
at
org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:199)
at
org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:180)
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.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:200)
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.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.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:165)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:1025)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:452)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1201)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Can this be because the user rangerusersync is not in ldap? Although in
spite of the error the initial sync was successful and I could see messages
like this later on:
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
2020-12-02 08:29:49,058 [http-bio-6080-exec-7] INFO
org.apache.ranger.security.listener.SpringEventListener
(SpringEventListener.java:70) - Login Successful:rangerusersync | Ip
Address:127.0.0.1 | sessionId=5CEDC9023EA19CDA63F16A06345616F7 |
Epoch=1606897789058
2020-12-02 08:29:49,058 [http-bio-6080-exec-7] DEBUG
springframework.security.web.authentication.www.BasicAuthenticationFilter
(BasicAuthenticationFilter.java:183) - Authentication success:
org.springframework.security.authentication.UsernamePasswordAuthenticationToken@836aa06d:
Principal: org.springframework.security.core.userdetails.User@826172bb:
Username: rangerusersync; Password: [PROTECTED]; Enabled: true;
AccountNonExpired: true; credentialsNonExpired: true; AccountNonLocked:
true; Granted Authorities: ROLE_SYS_ADMIN; Credentials: [PROTECTED];
Authenticated: true; Details:
org.springframework.security.web.authentication.WebAuthenticationDetails@fffe3f86:
RemoteIpAddress: 127.0.0.1; SessionId: 5CEDC9023EA19CDA63F16A06345616F7;
Granted Authorities: ROLE_SYS_ADMIN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Let me know if you need any further details.
Thanks,
Geri
Sailaja Polavarapu <sp...@cloudera.com> ezt írta (időpont: 2020. dec.
2., Sze, 2:30):
>
> Hi Geri,
> I haven't seen this issue in my local setup. From the above logs, I see
that "valid cookie is saved" after first sync, but in the next sync cycle
usersync is using credential login which is strange. In Usersync, for every
request to ranger admin, first try with the saved cookie (which is the
rangeradminsessionid). If it fails, then try with credentials. Can you
provide ranger admin logs to see - 1. why the session is invalid, 2. why
the rangerusersync creds login is failing.
>
> Thanks,
> Sailaja.
>
> On Sat, Nov 28, 2020 at 5:45 PM Gergely Lendvai <
gergely.lendvai93@gmail.com> wrote:
>>
>> Hi!
>>
>> I am trying to solve this for a while, but with no luck so far. I
managed to set up the usersync plugin with ldap (and without kerberos) and
after starting it the initial users are showing up on Ranger, but all the
upcoming hourly syncs are failing with the following error, which is a bit
misleading since it is just a warning:
>>
-------------------------------------------------------------------------------------------------------------------------------
>> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
response from ranger is 401.
>>
-------------------------------------------------------------------------------------------------------------------------------
>>
>> I enabled debug logs to get a clearer picture, but what is odd that at
the beginning my credentials are still valid and a new ranger cookie will
be created for the initial sync, but for the next hour something happens.
Here are the first couple of lines from the initial sync:
>>
-------------------------------------------------------------------------------------------------------------------------------
>> INFO UserGroupSync [UnixUserSyncThread] - Begin: initial load of
user/group from source==>sink
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
LdapDeltaUserGroupBuilder updateSink started
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
search first
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
extendedUserSearchFilter =
(&(objectclass=person)(|(uSNChanged>=0)(modifyTimestamp>=19700101000000Z)))
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
5564and currentDeltaSyncTime = 5564
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
addPMAccount(awsadmind-906714de98)
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.getMUser()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> ttributes":"{}"}
>> INFO LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - valid cookie
saved
>>
-------------------------------------------------------------------------------------------------------------------------------
>>
>> And these are the logs for an upcoming hour:
>>
-------------------------------------------------------------------------------------------------------------------------------
>> INFO UserGroupSync [UnixUserSyncThread] - Begin: update user/group from
source==>sink
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
LdapDeltaUserGroupBuilder updateSink started
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - Performing user
search first
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] -
extendedUserSearchFilter =
(&(objectclass=person)(|(uSNChanged>=5631)(modifyTimestamp>=19700101000005Z)))
>> INFO LdapDeltaUserGroupBuilder [UnixUserSyncThread] - uSNChangedVal =
5564and currentDeltaSyncTime = 5564
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - INFO:
addPMAccount(awsadmind-906714de98)
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.getMUser()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.cookieBasedUploadEntity()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - ==>
LdapPolicyMgrUserGroupBuilder.tryUploadEntityInfoWithCred()
>> DEBUG LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - USER GROUP
MAPPING{"loginId":"awsadmind-906714de98","firstName":"awsadmind-906714de98","lastName":"awsadmind-906714de98","userRoleList":[null],"otherA
>> ttributes":"{}"}
>> WARN LdapPolicyMgrUserGroupBuilder [UnixUserSyncThread] - Credentials
response from ranger is 401.
>>
-------------------------------------------------------------------------------------------------------------------------------
>>
>> Could you help figure this out? I am happy to share more details if
necessary.
>>
>> Thanks,
>> Geri
>