On 02/01/10 13:26, Vincent Deschênes wrote:
>
> Thanks Ronald,
>
>
>
> I did changed the log level, here is what it give:
>
>
>
> Is this the "domain that failed" log you were talking about ?
>
Vincent.
yes, the log msg includes the info that I was looking for.
It indicates that a a failed check of the following permission
javax.security.jacc.EJBMethodPermission
name: FepInterfaceService
actions:
preAllocateAssessment,ServiceEndpoint,com.stelvio.WebService.fep.PreAllocateAssessmentRequest))
method-name: preAllocateAssessment
method-interface-name: ServiceEndpoint
method-params:
com.stelvio.WebService.fep.PreAllocateAssessmentRequest
in policy context
AllianzAssessment/EJB_jar
the protection domain, indicates that the caller is
org.glassfish.security.common.PrincipalImpl "aalmtlp2"
and that the caller is a member of the following groups
org.glassfish.security.common.Group "GCRassessorAllocation",
org.glassfish.security.common.Group "GCRcostcontrol",
org.glassfish.security.common.Group "GCRpublic",
the caller also has an additional (user) principal which is a little
suspicious, i.e.,
org.glassfish.security.common.PrincipalImpl "username"
as it appears that the authentication process may be incorrectly adding the
"username" key as the value of the principal. It may be that the value
associated with
the "username" key is something like "Bill", and the authentication
process should be
creating a principal with that value.
>
>
>
> [#|2010-02-01T11:56:04.314-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.provider.BasePolicyWrapper$2;MethodName=run;|*Domain
> that failed*(ProtectionDomain (file:/AllianzAssessment/EJB_jar <no
> signer certificates>
>
the following log msgs; appear to indicate that login did succeed for
user "username"; which may be what you expected.
>
>
>
> ---
>
> [#|2010-02-01T11:56:04.272-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.jmac.callback|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.jmac.callback.BaseContainerCallbackHandler;MethodName=processPasswordValidation;|JMAC:
> In PasswordValidationCallback Processor|#]
>
> [#|2010-02-01T11:56:04.272-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.auth.login|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.auth.login.LoginContextDriver;MethodName=jmacLogin;|jmac
> login user [username] into realm: StelvioJDBCRealm using JAAS module:
> StelvioJDBCRealm|#]
>
> [#|2010-02-01T11:56:04.272-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=initialize;|Login
> module initialized: class
> com.stelvio.security.authentication.StelvioLoginModule|#]
>
> [#|2010-02-01T11:56:04.309-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=login;|JAAS
> login complete.|#]
>
> [#|2010-02-01T11:56:04.310-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.appserv.security|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.appserv.security.AppservPasswordLoginModule;MethodName=commit;|JAAS
> authentication committed.|#]
>
> [#|2010-02-01T11:56:04.310-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.auth.login|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.auth.login.LoginContextDriver;MethodName=jmacLogin;|jmac
> Password login succeeded for : username|#]
>
> [#|2010-02-01T11:56:04.310-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.jmac.callback|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.jmac.callback.BaseContainerCallbackHandler;MethodName=processPasswordValidation;|JMAC:
> authentication succeeded for user = |#]
>
the preceding msg is a little surprising, as based on the trace so far,
I would expect, user = "username" |#
>
>
> [#|2010-02-01T11:56:04.312-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=34;_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 java.lang.Thread.run(Thread.java:619)
> |#]
>
> [#|2010-02-01T11:56:04.313-0500|INFO|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=34;_ThreadName=Thread-1;|JACC
> Policy Provider: Failed Permission Check,
> context(AllianzAssessment/EJB_jar)-
> permission((javax.security.jacc.EJBMethodPermission
> FepInterfaceService
> preAllocateAssessment,ServiceEndpoint,com.stelvio.WebService.fep.PreAllocateAssessmentRequest))|#]
>
> [#|2010-02-01T11:56:04.314-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=34;_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 "username")
>
> java.security.Permissions_at_1117f0 (
> ...
> )
>
anyway, at this point, we know what permission was being checked, and
what principals were being checked for the
permission. If you could also provide the policy files under
domains/domainx/gnerated/policy/AllianzAssessment/EJB_jar/...
we can see what policy should have been in effect, and thus whether the
permission should have been granted.
It looks like you are using a custom JDBC realm.
Do you expect the realm to add a principal with name "username"?
If not, what caller identity do you expect to be established?
Ron
>
> )|#]
>
> [#|2010-02-01T11:56:04.317-0500|FINE|glassfishv3.0|javax.enterprise.system.core.security.com.sun.enterprise.security.webservices|_ThreadID=34;_ThreadName=Thread-1;ClassName=com.sun.enterprise.security.webservices.CommonServerSecurityPipe;MethodName=processResponse;|ws.status_secure_response|#]
>
> ---
>
>
>
> I personally do not really understand where is the problem from these
> logs. Could there be an intermittent persmission problem on the
> ejb.jar package file on the server?
>
>
>
> Thanks.
>
>
>
> VD
>
>
>
> ps. Yes I think Stelvio is as in passo de Stelvio, company founder has
> Italian origin.
>
>
>
> *From:* Ronald.Monzillo_at_Sun.COM [mailto:Ronald.Monzillo_at_Sun.COM]
> *Sent:* Thursday, January 28, 2010 6:08 PM
> *To:* users_at_glassfish.dev.java.net
> *Subject:* Re: JACC Intermittent problem
>
>
>
> On 01/28/10 16:55, Vincent Deschênes wrote:
>
> We have an application that is serving web service from ejb.
>
>
>
> When testing our web service we have intermittent authorization error
> with log like this:
>
>
>
> INFO|glassfishv3.0|javax.enterprise.system.core.security|_ThreadID=35;_ThreadName=Thread-1;|JACC
> Policy Provider: Failed Permission Check,
> context(applicationName/EJB_jar)-
> permission((javax.security.jacc.EJBMethodPermission
> FepInterfaceService
> preAllocateAssessment,ServiceEndpoint,com.stelvio.WebService.fep.PreAllocateAssessmentRequest))|#]
>
>
>
>
> The exact same request can pass many times and suddenly give this
> error once or twice and then it will continue to work.
>
>
>
> We have tried both JACC provider (default and simple) with the
> same result.
>
>
>
> Anyone has an idea ?
>
> Vincent,
>
> Since both providers are effected, my hunch is that there may be a
> problem in the authentication state, perhaps a
> problem with the protection domain cache, the realm, or the role
> mapping system.
>
> In any event, if you set the security logging level to FINE, and
> configure the default policy provider,
> then the provider will also log the failing protection domain; which
> will let us see what principals are
> being applied in the access decision.
>
> asadmin list-logger-levels
> asadmin set-log-level javax.enterprise.system.core.security=FINE
>
> unfortunately, a lot more stuff will appear in the log. hopefully you
> will still be able to reproduce the problem.
>
> the interesting log message will come from line 411 of
> BasePolicyWrapper.java
>
> if (logger.isLoggable(Level.FINE)) {
> logger.fine("Domain that failed(" + domain2 + ")");
> }
>
> if setting the security logger to FINE, is too intrusive, and you
> think you can change the isLoggable call to check for Level.INFO,
> rebuild the provider, and replace the corresponding module, you might
> want to give that a try.
>
> In any event, please let me know if you are able to make any progress
> with either of the above approaches.
> If you get the failure, and can show me the protection domain, and the
> associated granted.policy file, I may be
> able to see what is going wrong.
>
> Ron
>
> ps; Stevio as in passo de Stelvio?
>
>
>
>
> Thanks.
>
>
>
>
>
> VD
>
>
>