ldap credentials cache

3 views

Skip to first unread message

Conrad Leonard

unread,

Dec 1, 2015, 7:10:13 AM12/1/15

to Stardog

Using 4.0 with LDAP authn; still getting lots of traffic to LDAP server on every click in the web console. I would have thought the credentials cache would mitigate that. The relevant bit of our stardog.properties file:

security.realms = ldap
ldap.provider.url = ldap://bioldapv01.adqimr.ad.lan
ldap.security.principal = cn=manager,dc=genomeinfo,dc=qimrberghofer,dc=edu,dc=au
ldap.security.credentials = ***********
ldap.user.dn.template = uid={0},ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au
ldap.group.lookup.string = ou=Groups,dc=genomeinfo,dc=qimrberghofer,dc=edu,dc=au
ldap.users.cn = stardogUsers
ldap.superusers.cn = stardogSuperUsers
ldap.cache.invalidate.time = 1h

Authentication works fine, but from the traffic to ldap server it looks like the cache isn't operating as I would expect.

Any suggestions for what/how to troubleshoot?

thanks,

Edgar Rodriguez

unread,

Dec 1, 2015, 4:00:55 PM12/1/15

to sta...@clarkparsia.com

Thanks for the report, we’re taking a look at this and we’ll get back to you.

Any suggestions for what/how to troubleshoot?

In the meantime, you could enable logging for `org.apache.shiro.*` and check if there’s anything that may point to the issue.

Best,

— Edgar

Conrad Leonard

unread,

Dec 1, 2015, 9:54:18 PM12/1/15

to Stardog

Hi Edgar;

At your suggestion, logging set at DEBUG for org.apache.shiro, appending to stardog.log file.

The stardog.properties file settings are same as before (notably: ldap.cache.invalidate.time = 1h)

Tailing logs on LDAP server confirms that there is lots of traffic every time the user does anything in the UI that requires more info from the db.

Here's what I see in the logs on server start:

WARN  2015-12-02 12:32:15,975 [main] com.complexible.stardog.security.impl.AbstractExistingSecurityResourcesLoader:roleAssignmentsMap(316): Ignoring role assignment for unrecognized user: null
WARN  2015-12-02 12:32:15,985 [main] com.complexible.stardog.security.impl.AbstractExistingSecurityResourcesLoader:permissionsMap(379): Ignoring permission for unrecognized subject: tag:stardog.com:2011-10-11:stardog:security:User:3c3cafcd59029cf102f6c0d8e0f28048
WARN  2015-12-02 12:32:15,986 [main] com.complexible.stardog.security.impl.AbstractExistingSecurityResourcesLoader:permissionsMap(379): Ignoring permission for unrecognized subject: tag:stardog.com:2011-10-11:stardog:security:User:b48f0ce6d66b7c4280c061573a3df87a
DEBUG 2015-12-02 12:32:16,010 [main] org.apache.shiro.realm.ldap.JndiLdapRealm:setUserDnTemplate(196): Determined user DN prefix [uid=] and suffix [,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au]
DEBUG 2015-12-02 12:32:16,011 [main] org.apache.shiro.realm.AuthorizingRealm:getAuthorizationCacheLazy(234): No authorizationCache instance set.  Checking for a cacheManager...
DEBUG 2015-12-02 12:32:16,011 [main] org.apache.shiro.realm.AuthorizingRealm:getAuthorizationCacheLazy(242): CacheManager [TimeConstrainedCacheManager with 0 cache(s)): []] has been configured.  Building authorization cache named [com.complexible.stardog.security.ldap.LDAPRealm.authorizationCache]
Initializing Stardog
WARN  2015-12-02 12:32:16,131 [main] com.complexible.stardog.metadata.MetadataIO:readBytes(260): Unrecognized option in the metadata: search.version

************************************************************
This copy of Stardog is licensed to Conrad Leonard (xxxxxxxxxxxxxxxxx), QIMR Berghofer
This is a Community license
This license does not expire.
************************************************************

                                                             :;   
                                      ;;                   `;`:   
  `'+',    ::                        `++                    `;:`  
 +###++,  ,#+                        `++                    .     
 ##+.,',  '#+                         ++                     +    
,##      ####++  ####+:   ##,++` .###+++   .####+    ####++++#    
`##+     ####+'  ##+#++   ###++``###'+++  `###'+++  ###`,++,:     
 ####+    ##+        ++.  ##:   ###  `++  ###  `++` ##`  ++:      
  ###++,  ##+        ++,  ##`   ##;  `++  ##:   ++; ##,  ++:      
    ;+++  ##+    ####++,  ##`   ##:  `++  ##:   ++' ;##'#++       
     ;++  ##+   ###  ++,  ##`   ##'  `++  ##;   ++:  ####+        
,.   +++  ##+   ##:  ++,  ##`   ###  `++  ###  .++  '#;           
,####++'  +##++ ###+#+++` ##`   :####+++  `####++'  ;####++`      
`####+;    ##++  ###+,++` ##`    ;###:++   `###+;   `###++++      
                                                    ##   `++      
                                                   .##   ;++      
                                                    #####++`      
                                                     `;;;.        

************************************************************

Stardog server 4.0 started on Wed Dec 02 12:32:16 AEST 2015.

Stardog server is listening on all network interfaces.
SNARL server available at snarl://localhost:5820.
HTTP server available at http://localhost:5820.
SSL is enabled for any incoming client connections.

STARDOG_HOME=/data/stardog/default

Now I log in to the web console as an LDAP authenticated user and click on a single link in the class tree browser:

DEBUG 2015-12-02 12:34:23,346 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,346 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,355 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,355 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,356 [SPEC-Server-1-1] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,356 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,357 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractValidatingSessionManager:createSessionValidationScheduler(213): No sessionValidationScheduler set. Attempting to create default instance.

INFO 2015-12-02 12:34:23,358 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractValidatingSessionManager:enableSessionValidation(230): Enabling session validation scheduler...

DEBUG 2015-12-02 12:34:23,360 [SPEC-Server-1-1] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,721 [SPEC-Server-1-1] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,723 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [c187948b-02f3-460a-83a7-f13cdb050996]

DEBUG 2015-12-02 12:34:23,745 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,745 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,752 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,753 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,753 [SPEC-Server-1-2] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,753 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,753 [SPEC-Server-1-2] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,778 [SPEC-Server-1-2] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,778 [SPEC-Server-1-2] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [ebccc0ca-1e5b-4510-b913-b305bf0ffbb9]

DEBUG 2015-12-02 12:34:23,786 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,786 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,793 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,793 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,794 [SPEC-Server-1-3] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,794 [SPEC-Server-1-3] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,794 [SPEC-Server-1-3] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,815 [SPEC-Server-1-3] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,815 [SPEC-Server-1-3] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [f25742db-fdf8-494f-90ef-672350f89a81]

DEBUG 2015-12-02 12:34:23,824 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,825 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,831 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,831 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,831 [SPEC-Server-1-4] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,831 [SPEC-Server-1-4] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,831 [SPEC-Server-1-4] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,850 [SPEC-Server-1-4] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,851 [SPEC-Server-1-4] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [a6462755-b7ac-4721-b8b3-41ae3466b552]

DEBUG 2015-12-02 12:34:23,858 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,858 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,865 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,865 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,865 [SPEC-Server-1-5] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,865 [SPEC-Server-1-5] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,865 [SPEC-Server-1-5] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,883 [SPEC-Server-1-5] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,883 [SPEC-Server-1-5] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [e0359cfe-3dc3-4609-a6e4-327558d56d51]

DEBUG 2015-12-02 12:34:23,890 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,891 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,899 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,899 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,899 [SPEC-Server-1-6] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,900 [SPEC-Server-1-6] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,900 [SPEC-Server-1-6] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,921 [SPEC-Server-1-6] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,922 [SPEC-Server-1-6] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [88bacc4d-77a1-4630-af81-b53be3a1c855]

DEBUG 2015-12-02 12:34:23,929 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,930 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,936 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,936 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,936 [SPEC-Server-1-7] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,937 [SPEC-Server-1-7] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,937 [SPEC-Server-1-7] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,959 [SPEC-Server-1-7] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,959 [SPEC-Server-1-7] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [627fc79d-6be1-4884-aac6-6b5fbbc2ac92]

DEBUG 2015-12-02 12:34:23,966 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:23,966 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:23,973 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:23,973 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:23,973 [SPEC-Server-1-8] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:23,973 [SPEC-Server-1-8] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:23,973 [SPEC-Server-1-8] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:23,992 [SPEC-Server-1-8] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:23,993 [SPEC-Server-1-8] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [f8ad5ab5-8d69-465b-b7d8-0e26ff264c21]

DEBUG 2015-12-02 12:34:24,000 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,000 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,006 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,006 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,006 [SPEC-Server-1-1] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,006 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,007 [SPEC-Server-1-1] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,025 [SPEC-Server-1-1] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,025 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [729fced0-4f5b-44b6-87db-c7a6b798c439]

DEBUG 2015-12-02 12:34:24,031 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,032 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,038 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,038 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,038 [SPEC-Server-1-2] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,039 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,039 [SPEC-Server-1-2] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,055 [SPEC-Server-1-2] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,055 [SPEC-Server-1-2] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [8c976d5a-0705-47a9-9fad-77ee3c080f81]

DEBUG 2015-12-02 12:34:24,060 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,061 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,067 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,067 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,068 [SPEC-Server-1-3] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,068 [SPEC-Server-1-3] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,068 [SPEC-Server-1-3] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,085 [SPEC-Server-1-3] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,085 [SPEC-Server-1-3] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [4b58f91d-1ad8-46e0-afc3-dc144cf0cdb7]

DEBUG 2015-12-02 12:34:24,094 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,094 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,100 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,101 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,101 [SPEC-Server-1-4] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,101 [SPEC-Server-1-4] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,101 [SPEC-Server-1-4] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,122 [SPEC-Server-1-4] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,122 [SPEC-Server-1-4] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [69f5a5c3-2540-449d-b2ed-100a0435db0e]

DEBUG 2015-12-02 12:34:24,137 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,137 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,142 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,142 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,142 [SPEC-Server-1-5] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,142 [SPEC-Server-1-5] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,142 [SPEC-Server-1-5] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,159 [SPEC-Server-1-5] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,159 [SPEC-Server-1-5] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [bc497b25-894a-4040-a025-d9ae40721910]

DEBUG 2015-12-02 12:34:24,175 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,175 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,181 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,181 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,181 [SPEC-Server-1-6] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,181 [SPEC-Server-1-6] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,181 [SPEC-Server-1-6] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,197 [SPEC-Server-1-6] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,197 [SPEC-Server-1-6] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [3fd44782-fe8e-4bcd-a6f0-4fe739460349]

DEBUG 2015-12-02 12:34:24,206 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP

DEBUG 2015-12-02 12:34:24,207 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled

DEBUG 2015-12-02 12:34:24,212 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo

DEBUG 2015-12-02 12:34:24,213 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL]. Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].

DEBUG 2015-12-02 12:34:24,213 [SPEC-Server-1-7] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false]. Returned account [conradL]

DEBUG 2015-12-02 12:34:24,213 [SPEC-Server-1-7] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map. Falling back to SecurityUtils.getSecurityManager() lookup.

DEBUG 2015-12-02 12:34:24,213 [SPEC-Server-1-7] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]

DEBUG 2015-12-02 12:34:24,229 [SPEC-Server-1-7] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL

DEBUG 2015-12-02 12:34:24,229 [SPEC-Server-1-7] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [f3ba225e-629c-4e61-8f8e-6109d314af98]

Now, after waiting a minute so that the log entries are more easily grouped to the eye by time, I click again on a (different) link in the web console class browser:

DEBUG 2015-12-02 12:35:32,183 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,184 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,191 [SPEC-Server-1-8] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,208 [SPEC-Server-1-8] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,208 [SPEC-Server-1-8] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [9ad59551-4afb-4c86-aa18-0702c2d254ef]
DEBUG 2015-12-02 12:35:32,215 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,215 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,221 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,221 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,221 [SPEC-Server-1-1] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,221 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,221 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,222 [SPEC-Server-1-1] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,238 [SPEC-Server-1-1] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,238 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [1927bc51-74e2-49f9-afda-11db9ed38b2d]
DEBUG 2015-12-02 12:35:32,245 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,245 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,251 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,251 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,251 [SPEC-Server-1-2] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,251 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,252 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,252 [SPEC-Server-1-2] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,266 [SPEC-Server-1-2] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,266 [SPEC-Server-1-2] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [e395a006-8523-4aa5-b8dd-2fb1153d8b7a]
DEBUG 2015-12-02 12:35:32,273 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,273 [SPEC-Server-1-3] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,279 [SPEC-Server-1-3] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,294 [SPEC-Server-1-3] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,294 [SPEC-Server-1-3] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [18502f27-9c6b-4813-9050-f4caa281acfc]
DEBUG 2015-12-02 12:35:32,300 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,300 [SPEC-Server-1-4] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,306 [SPEC-Server-1-4] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,321 [SPEC-Server-1-4] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,321 [SPEC-Server-1-4] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [2e133b2d-14cc-47ee-bba7-2ca7c6781902]
DEBUG 2015-12-02 12:35:32,329 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,329 [SPEC-Server-1-5] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,334 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,334 [SPEC-Server-1-5] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,334 [SPEC-Server-1-5] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,335 [SPEC-Server-1-5] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,335 [SPEC-Server-1-5] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,335 [SPEC-Server-1-5] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,360 [SPEC-Server-1-5] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,360 [SPEC-Server-1-5] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [ec678ee3-8227-496b-b0e5-86f4c1e4f858]
DEBUG 2015-12-02 12:35:32,367 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,367 [SPEC-Server-1-6] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,373 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,374 [SPEC-Server-1-6] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,374 [SPEC-Server-1-6] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,374 [SPEC-Server-1-6] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,374 [SPEC-Server-1-6] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,374 [SPEC-Server-1-6] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,389 [SPEC-Server-1-6] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,389 [SPEC-Server-1-6] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [6bcdabc3-99a3-491c-894f-60f154d50cda]
DEBUG 2015-12-02 12:35:32,397 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,397 [SPEC-Server-1-7] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,404 [SPEC-Server-1-7] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,419 [SPEC-Server-1-7] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,419 [SPEC-Server-1-7] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [ee151ae0-992e-49c4-b7c7-3f421068848b]
DEBUG 2015-12-02 12:35:32,432 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,432 [SPEC-Server-1-8] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,441 [SPEC-Server-1-8] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,457 [SPEC-Server-1-8] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,457 [SPEC-Server-1-8] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [abdd5dd8-1fff-4aa2-a581-8da531b85c8e]
DEBUG 2015-12-02 12:35:32,466 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,466 [SPEC-Server-1-1] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,471 [SPEC-Server-1-1] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,487 [SPEC-Server-1-1] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,487 [SPEC-Server-1-1] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [5587201f-8b1b-4e8b-a976-2c914da287e1]
DEBUG 2015-12-02 12:35:32,497 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapRealm:queryForAuthenticationInfo(369): Authenticating user 'conradL' through LDAP
DEBUG 2015-12-02 12:35:32,497 [SPEC-Server-1-2] org.apache.shiro.realm.ldap.JndiLdapContextFactory:getLdapContext(488): Initializing LDAP context using URL [ldap://bioldapv01.adqimr.ad.lan] and principal [uid=conradL,ou=People,dc=meta,dc=qimrberghofer,dc=edu,dc=au] with pooling disabled
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:getAuthenticationInfo(569): Looked up AuthenticationInfo [conradL] from doGetAuthenticationInfo
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.realm.AuthenticatingRealm:cacheAuthenticationInfoIfPossible(507): AuthenticationInfo caching is disabled for info [conradL].  Submitted token: [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.authc.AbstractAuthenticator:authenticate(231): Authentication successful for token [org.apache.shiro.authc.UsernamePasswordToken - conradL, rememberMe=false].  Returned account [conradL]
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.subject.support.DefaultSubjectContext:resolveSecurityManager(102): No SecurityManager available in subject context map.  Falling back to SecurityUtils.getSecurityManager() lookup.
DEBUG 2015-12-02 12:35:32,503 [SPEC-Server-1-2] org.apache.shiro.session.mgt.DefaultSessionManager:create(175): Creating new EIS record for new session instance [org.apache.shiro.session.mgt.SimpleSession,id=null]
DEBUG 2015-12-02 12:35:32,521 [SPEC-Server-1-2] org.apache.shiro.mgt.DefaultSecurityManager:logout(550): Logging out subject with primary principal conradL
DEBUG 2015-12-02 12:35:32,522 [SPEC-Server-1-2] org.apache.shiro.session.mgt.AbstractSessionManager:stop(244): Stopping session with id [21e6d571-f9f9-47de-aead-67dbf24768d5]

I don't know anything about shiro, but the logs look helpful, and suggest something is not configured correctly.

cheers,

Edgar Rodriguez

unread,

Dec 4, 2015, 1:11:25 PM12/4/15

to sta...@clarkparsia.com

Hello Conrad,

On Dec 1, 2015, at 9:54 PM, Conrad Leonard <conrad....@hotmail.com> wrote:

Hi Edgar;
At your suggestion, logging set at DEBUG for org.apache.shiro, appending to stardog.log file.

The stardog.properties file settings are same as before (notably: ldap.cache.invalidate.time = 1h)

Tailing logs on LDAP server confirms that there is lots of traffic every time the user does anything in the UI that requires more info from the db.

Thank you for sending the logs. We have identified the problem, happening because caching is not enabled for authentication, just for authorization.

We created issue #2698 for this and it’ll be fixed in the next release.

Best,

— Edgar

Conrad Leonard

unread,

Dec 4, 2015, 6:00:24 PM12/4/15

to sta...@clarkparsia.com

Great, thanks Edgar.

--
-- --
You received this message because you are subscribed to the C&P "Stardog" group.
To post to this group, send email to sta...@clarkparsia.com
To unsubscribe from this group, send email to
stardog+u...@clarkparsia.com
For more options, visit this group at
http://groups.google.com/a/clarkparsia.com/group/stardog?hl=en
---
You received this message because you are subscribed to a topic in the Google Groups "Stardog" group.
To unsubscribe from this topic, visit https://groups.google.com/a/clarkparsia.com/d/topic/stardog/wjrLRTBXHOo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to stardog+u...@clarkparsia.com.

Reply all

Reply to author

Forward

0 new messages