users@glassfish.java.net

RE: JACC Intermittent problem

From: Vincent Deschênes <vdeschenes_at_stelvio.com>
Date: Wed, 17 Feb 2010 13:30:27 -0500

Hi Ronald,
I got some new informations regarding this problem. I would really appreciate if you could look at it.

I got my new logs, the username does not change during the call to authenticateUser. The authentication system is simply not
authenticating the good user.

In the following log, the user "colinweb1" is making a web service call and the LoginModule is asked to anthenticate "aalmtlp2" user
!
At the end the realm contains both user principals but only the group of aalmtlp2.

This log "Stelvio Login module: threadId:50 [step 1] authenticating User: aalmtlp2" is simply logging the value of "_username" at
the first line of authenticateUser();

It is bettween these two other log lines :

jmac login user [colinweb1] into realm: StelvioJDBCRealm using JAAS module: StelvioJDBCRealm
Stelvio Login module authenticating User: aalmtlp2
jmac Password login succeeded for : colinweb1


We are using wsit with username token authentication on web service implemented on stateless ejb.

The problem only occure for web service calls.

What could cause this problem ?
Could there be a bug in glassfish related to web service user authentication ?

Our stateless ejb are declaring a SessionContext like this :
  @Resource
  SessionContext context;

could it be related ?

Please help !!!



[#|2010-02-17T08:55:21.522-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.jmac.callback|_
ThreadID=36;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.jmac.callback.BaseContainerCallbackHandler;MethodName=process
PasswordValidation;|JMAC: In PasswordValidationCallback Processor|#]

[#|2010-02-17T08:55:21.522-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.auth.login|_Thr
eadID=36;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.auth.login.LoginContextDriver;MethodName=jmacLogin;|jmac login
user [colinweb1] into realm: StelvioJDBCRealm using JAAS module: StelvioJDBCRealm|#]

[#|2010-02-17T08:55:21.524-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=36;_Thre
adName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=initialize;|Login module initialized: class
com.stelvio.security.authentication.StelvioLoginModule|#]

[#|2010-02-17T08:55:21.524-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 [step 1] authenticating User: aalmtlp2|#]

[#|2010-02-17T08:55:21.524-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 [step 2] authenticating User: aalmtlp2|#]

[#|2010-02-17T08:55:21.524-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 [step 3] authenticating User: aalmtlp2|#]

[#|2010-02-17T08:55:21.540-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 [step 4] authenticating User: aalmtlp2|#]

[#|2010-02-17T08:55:21.542-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 [step 5] authenticating User: aalmtlp2|#]

[#|2010-02-17T08:55:21.544-0500|INFO|glassfishv3.0|com.stelvio.security.authentication.StelvioLoginModule|_ThreadID=36;_ThreadName=T
hread-1;|Stelvio Login module: threadId:50 Calling commitUserAuthentication userName: aalmtlp2 _username: aalmtlp2 groups:
GCRassessorAllocation|GCRcostcontrol|GCRpublic||#]

[#|2010-02-17T08:55:21.544-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=36;_Thre
adName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=login;|JAAS login complete.|#]

[#|2010-02-17T08:55:21.546-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=36;_Thre
adName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=commit;|JAAS authentication committed.|#]

[#|2010-02-17T08:55:21.546-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.auth.login|_Thr
eadID=36;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.auth.login.LoginContextDriver;MethodName=jmacLogin;|jmac
Password login succeeded for : colinweb1|#]

[#|2010-02-17T08:55:21.546-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.jmac.callback|_
ThreadID=36;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.jmac.callback.BaseContainerCallbackHandler;MethodName=process
PasswordValidation;|JMAC: authentication succeeded for user = |#]

[#|2010-02-17T08:55:21.548-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=36;_ThreadName=Thread-1;ClassName
=com.sun.enterprise.security.provider.BasePolicyWrapper;MethodName=doImplies;|JACC Policy Provider, failed Permission Check at :
java.lang.Exception
        at com.sun.enterprise.security.provider.BasePolicyWrapper.doImplies(BasePolicyWrapper.java:404)
        at com.sun.enterprise.security.provider.BasePolicyWrapper.implies(BasePolicyWrapper.java:246)
        at org.glassfish.ejb.security.application.EJBSecurityManager.authorize(EJBSecurityManager.java:712)
        at com.sun.ejb.containers.BaseContainer.authorize(BaseContainer.java:2249)
        at com.sun.ejb.EjbInvocation.authorizeWebService(EjbInvocation.java:639)
        at com.sun.enterprise.security.authorize.EJBPolicyContextDelegate.authorize(EJBPolicyContextDelegate.java:93)
        at com.sun.enterprise.security.jmac.provider.config.PipeHelper.authorize(PipeHelper.java:252)
        at com.sun.enterprise.security.webservices.CommonServerSecurityPipe.processRequest(CommonServerSecurityPipe.java:181)
        at com.sun.enterprise.security.webservices.CommonServerSecurityPipe.process(CommonServerSecurityPipe.java:127)
        at com.sun.xml.ws.api.pipe.helper.PipeAdapter.processRequest(PipeAdapter.java:115)
        at com.sun.xml.ws.api.pipe.Fiber.__doRun(Fiber.java:629)
        at com.sun.xml.ws.api.pipe.Fiber._doRun(Fiber.java:588)
        at com.sun.xml.ws.api.pipe.Fiber.doRun(Fiber.java:573)
        at com.sun.xml.ws.api.pipe.Fiber.runSync(Fiber.java:470)
        at com.sun.xml.ws.server.WSEndpointImpl$2.process(WSEndpointImpl.java:295)
        at com.sun.xml.ws.transport.http.HttpAdapter$HttpToolkit.handle(HttpAdapter.java:515)
        at com.sun.xml.ws.transport.http.HttpAdapter.handle(HttpAdapter.java:285)
        at com.sun.xml.ws.transport.http.servlet.ServletAdapter.handle(ServletAdapter.java:143)
        at org.glassfish.webservices.Ejb3MessageDispatcher.handlePost(Ejb3MessageDispatcher.java:116)
        at org.glassfish.webservices.Ejb3MessageDispatcher.invoke(Ejb3MessageDispatcher.java:87)
        at org.glassfish.webservices.EjbWebServiceServlet.dispatchToEjbEndpoint(EjbWebServiceServlet.java:196)
        at org.glassfish.webservices.EjbWebServiceServlet.service(EjbWebServiceServlet.java:127)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
        at com.sun.grizzly.http.servlet.FilterChainImpl.doFilter(FilterChainImpl.java:195)
        at com.sun.grizzly.http.servlet.FilterChainImpl.invokeFilterChain(FilterChainImpl.java:139)
        at com.sun.grizzly.http.servlet.ServletAdapter.doService(ServletAdapter.java:376)
        at com.sun.grizzly.http.servlet.ServletAdapter.service(ServletAdapter.java:329)
        at com.sun.grizzly.tcp.http11.GrizzlyAdapter.service(GrizzlyAdapter.java:166)
        at com.sun.enterprise.v3.server.HK2Dispatcher.dispath(HK2Dispatcher.java:100)
        at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:245)
        at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
        at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693)
        at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954)
        at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
        at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
        at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
        at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
        at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
        at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
        at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
        at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
        at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
        at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
        at java.lang.Thread.run(Thread.java:619)
|#]

[#|2010-02-17T08:55:21.548-0500|INFO|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=36;_ThreadName=Thread-1;|JACC
Policy Provider: Failed Permission Check, context(AllianzAssessment/EJB_jar)- permission((javax.security.jacc.EJBMethodPermission
AALEstImageRefDataService
updateRegionPostcodes,ServiceEndpoint,au.com.allianz.schema.message.estimage.refdata.xsd._1_2_0.UpdateRegionPostcodesRequestType))|#
]

[#|2010-02-17T08:55:21.550-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=36;_ThreadName=Thread-1;ClassName
=com.sun.enterprise.security.provider.BasePolicyWrapper$2;MethodName=run;|Domain that failed(ProtectionDomain
(file:/AllianzAssessment/EJB_jar <no signer certificates>)
 null
 (principals org.glassfish.security.common.PrincipalImpl "aalmtlp2",
org.glassfish.security.common.Group "GCRassessorAllocation",
org.glassfish.security.common.Group "GCRcostcontrol",
org.glassfish.security.common.Group "GCRpublic",
org.glassfish.security.common.PrincipalImpl "colinweb1")

 java.security.Permissions_at_1eeb165 (
 (javax.management.MBeanPermission [com.sun.messaging.jms.*:*] *)
 (java.net.SocketPermission localhost:1024- listen,resolve)
 (java.net.SocketPermission * connect,resolve)
 (javax.security.auth.PrivateCredentialPermission javax.resource.spi.security.PasswordCredential * "*" read)
 (java.io.FilePermission /tmp/- delete)
 (java.io.FilePermission /stelvio/glassfishv3/glassfish/domains/domain1/lib/databases/- delete)
 (java.io.FilePermission <<ALL FILES>> read,write)
...)

)|#]

[#|2010-02-17T08:55:21.558-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.webservices|_Th
readID=36;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.webservices.CommonServerSecurityPipe;MethodName=processResponse
;|ws.status_secure_response|#]




Thanks.


Vincent Deschenes