-
1. Re: Repeated calls to LoginModule for EJB authentication
anil.saldhana Jan 9, 2007 6:21 PM (in response to kuzmiigo)For every ejb invocation, a security check is made. If the user is already authenticated, then his subject is picked from the security cache, if not a jaas login happens.
-
2. Re: Repeated calls to LoginModule for EJB authentication
kuzmiigo Jan 10, 2007 4:46 AM (in response to kuzmiigo)Thank you, Anil.
Although the subject is taken from the cache, I see that LoginModules's commit() method is called anyway. As I add "User logged in" to audit log in commit(), there are too much false "login" records in the log. I see two solutions:
1. To check whether login()/commit() are called for the first time (real login), or with the cached subject. Is it possible to distinguish these cases?
2. To add "login" records to the audit log in some other place. Where it should be placed?
Best regards,
Igor Kuzmitshov -
3. Re: Repeated calls to LoginModule for EJB authentication
anil.saldhana Jan 10, 2007 10:43 PM (in response to kuzmiigo)Ur login modules commit is only called when your jaas login process is successful. When the subject is retrieved from the cache, there is no jaas login and no login module lifecycle invoked.
It is possible that components in different security domains may be invoking the jaas login.
Why don't you try to enable trace level loggng as outlined in the security faq (look at the beginning of this security forum). -
4. Re: Repeated calls to LoginModule for EJB authentication
brownjamese Feb 8, 2007 1:32 PM (in response to kuzmiigo)Anil:
By cache are you refering to the cache maintained by JaasSecurityManagerService? ... configured through (in JBossAS 4.0.4GA) /deploy/security-service.xml? .. with the default configuration:!-- JAAS security manager and realm mapping --> <mbean code="org.jboss.security.plugins.JaasSecurityManagerService" name="jboss.security:service=JaasSecurityManager"> <attribute name="ServerMode">true</attribute> <attribute name="SecurityManagerClassName">org.jboss.security.plugins.JaasSecurityManager</attribute> <attribute name="DefaultUnauthenticatedPrincipal">anonymous</attribute> <attribute name="DefaultCacheTimeout">0</attribute> <attribute name="DefaultCacheResolution">0</attribute> </mbean>
The reason I ask is that we are encountering the same issue with a custom login module that extends AbstractServerLoginModule implementing only initialize, and login. Thus allowing the super's commit and logout to handle things.
-- James -
5. Re: Repeated calls to LoginModule for EJB authentication
brownjamese Feb 8, 2007 2:51 PM (in response to kuzmiigo)Interesting and odd log entries - especially since I don't know what a good "run" should look like. I followed the security FAQ and added the necessary log4j config entries. After trundling through the info, I still see:
* multiple access to the login module's login() method; and
* inserts into the cache with different subject reference Id
For example, I see the actual login:2007-02-08 14:58:03,121 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] Begin isValid, principal:U174791, cache info: null 2007-02-08 14:58:03,322 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] End isValid, true 2007-02-08 14:58:03,322 TRACE [org.jboss.web.tomcat.security.JBossSecurityMgrRealm] User: U174791 is authenticated 2007-02-08 14:58:03,332 TRACE [org.jboss.security.SecurityAssociation] pushSubjectContext, subject=Subject: Principal: Roles(members:xxx,yyy,zzz) Principal: U174791 , sc=org.jboss.security.SecurityAssociation$SubjectContext@7c7d85{principal=U174791,subject=18143033}
Then access to the next URL, where the "hit" on the web app checks (and finds) the subject in cache:2007-02-08 14:59:09,777 DEBUG [org.apache.catalina.core.ContainerBase.[jboss.web].[localhost]] Checking for SSO cookie 2007-02-08 14:59:09,777 DEBUG [org.apache.catalina.core.ContainerBase.[jboss.web].[localhost]] Checking for cached principal for D5612028A309EA8A4A5889D393B6251A 2007-02-08 14:59:09,777 DEBUG [org.apache.catalina.core.ContainerBase.[jboss.web].[localhost]] Found cached principal 'U174791' with auth type 'FORM'
But then access from web-app to EJB to EJB in another ear (all with same jaas policy configured) produces:2007-02-08 14:59:09,907 TRACE [org.jboss.security.SecurityAssociation] getPrincipal, principal=U174791 2007-02-08 14:59:09,907 TRACE [org.jboss.security.SecurityAssociation] pushSubjectContext, subject=null, sc=org.jboss.security.SecurityAssociation$SubjectContext@7aed3a{principal=U174791,subject=null} 2007-02-08 14:59:09,928 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null 2007-02-08 14:59:09,958 TRACE [org.jboss.security.SecurityAssociation] getPrincipal, principal=U174791 2007-02-08 14:59:09,958 TRACE [org.jboss.security.plugins.JaasSecurityManager$DomainInfo] destroy, subject=Subject: Principal: Roles(members:xxx,yyy,zzz) Principal: U174791 , this=org.jboss.security.plugins.JaasSecurityManager$DomainInfo@b05409[Subject(23167560).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.SimplePrincipal@22316052(U174791),credential.class=java.lang.String@23438274,expirationTime=1170961028413], activeUsers=0 2007-02-08 14:59:09,958 TRACE [org.jboss.security.plugins.JaasSecurityManager$DomainInfo] logout, subject=Subject: Principal: Roles(members:xxx,yyy,zzz) Principal: U174791 , this=org.jboss.security.plugins.JaasSecurityManager$DomainInfo@b05409[Subject(23167560).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.SimplePrincipal@22316052(U174791),credential.class=java.lang.String@23438274,expirationTime=1170961028413] 2007-02-08 14:59:09,968 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] Begin isValid, principal:U174791, cache info: null 2007-02-08 14:59:09,968 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] defaultLogin, principal=U174791 2007-02-08 14:59:09,968 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] Begin getAppConfigurationEntry(acol-core-policy), size=10 2007-02-08 14:59:09,968 TRACE [org.jboss.security.auth.login.XMLLoginConfigImpl] End getAppConfigurationEntry(acol-core-policy), authInfo=AppConfigurationEntry[]: [0] LoginModule Class: ca.acol.core.security.login.JBossLoginModule ControlFlag: LoginModuleControlFlag: sufficient Options:name=auth_ds, value=auth 2007-02-08 14:59:10,048 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] defaultLogin, lc=javax.security.auth.login.LoginContext@1be9101, subject=Subject(2223107).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.SimplePrincipal@22316052(U174791) 2007-02-08 14:59:10,048 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] updateCache, inputSubject=Subject(2223107).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.SimplePrincipal@22316052(U174791) 2007-02-08 14:59:10,048 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] Inserted cache info: org.jboss.security.plugins.JaasSecurityManager$DomainInfo@31ac05[Subject(17676813).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.SimplePrincipal@22316052(U174791),credential.class=java.lang.String@23438274,expirationTime=1170961148415] 2007-02-08 14:59:10,048 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] End isValid, true 2007-02-08 14:59:10,048 TRACE [org.jboss.security.SecurityAssociation] pushSubjectContext, subject=Subject: Principal: Roles(members:xxx,yyy,zzz) Principal: U174791 , sc=org.jboss.security.SecurityAssociation$SubjectContext@11492ed{principal=U174791,subject=28983194} 2007-02-08 14:59:10,048 TRACE [org.jboss.security.SecurityAssociation] pushRunAsIdentity, runAs=null
Just to clarify wars/jars/ears involved:
.ear
- .war - struts-based web application
- .jar - contains application-specific EJBs
payment.ear
- payment.jar - real-time payment interface
.war invokes .jar to perform custom workflow, including payment. Thus .jar calls EJBs in .jar.
Various incantations of security-domain have been used all with the same application policy. Log snippets above are from with .war and payment.jar with the security-domain set to acol-core-policy. I have tried adding the same security policy to .jar, but that just increases the number of re-authentication calls.
-- James
- -
6. Re: Repeated calls to LoginModule for EJB authentication
brownjamese Feb 9, 2007 12:07 PM (in response to kuzmiigo)Resolved the issue and answered my own question. In our case it was directly related to the JassSecurityManager configuration which had been changed to 0 for both DefaultCacheTimeout and DefaultCacheResolution. The interesting question that I am left with however, is why do I see the following in the logs if caching is, in essence, disabled:
14:59:10,048 TRACE [org.jboss.security.plugins.JaasSecurityManager.acol-core-policy] Inse
rted cache info: org.jboss.security.plugins.JaasSecurityManager$DomainInfo@31ac05[Subject(
17676813
).principals=org.jboss.security.SimpleGroup@28014118(Roles(members:xxx,yyy,zzz))org.jboss.security.S
implePrincipal@22316052(U174791),credential.class=java.lang.String@23438274,expirationTime=117096114
8415]
A quick peak at JassSecurityManager and the inner DomainInfo leads me to believe that there could be optimizations if DefaultCacheTimeout (aka lifetime) == 0.
-- James