search

payara / Payara

Payara Server is an open source middleware platform that supports reliable and secure deployments of Java EE (Jakarta EE) and MicroProfile applications in any environment: on premise, in the cloud or hybrid.
http://www.payara.fish
Other
883 stars 306 forks source link

JACC Policy Provider: Failed Permission Check on 4.1.154 cluster #507

Closed dorpsidioot closed 8 years ago

dorpsidioot commented 9 years ago

Regularly getting the JACC Policy Provider: Failed Permission Check error when deploying newer versions of the same application.

Example:

[#|2015-11-02T16:46:00.048+0100|WARNING|Payara 4.1|javax.enterprise.ejb.container|_MessageID=AS-EJB-00056;|A system exception occurred during an invocation on EJB ControlDatabaseController, method: public java.util.List be.powerdale.control.controllers.ControlDatabaseController.getChargesWithoutPayment(int)|#]

[#|2015-11-02T16:46:00.049+0100|WARNING|Payara 4.1|javax.enterprise.ejb.container||javax.ejb.AccessLocalException: Client not authorized for this invocation
    at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1960)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:210)
    at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
    at com.sun.proxy.$Proxy501.getChargesWithoutPayment(Unknown Source)
    at be.powerdale.control.controllers.__EJB31_Generated__ControlDatabaseController__Intf____Bean__.getChargesWithoutPayment(Unknown Source)
    at be.powerdale.control.logic.ChargeCheckHandler.checkForChargesToCalculate(ChargeCheckHandler.java:175)
    at be.powerdale.control.logic.ChargeCheckHandler.execute(ChargeCheckHandler.java:51)
    at be.powerdale.control.mdb.ControlMessageListener.handleTask(ControlMessageListener.java:88)
    at be.powerdale.control.mdb.ControlMessageListener.onMessage(ControlMessageListener.java:72)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1081)
    at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1153)
    at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4786)
    at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:656)
    at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:824)
    at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:608)
    at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
    at org.jboss.weld.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
    at sun.reflect.GeneratedMethodAccessor1798.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:883)
    at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:823)
    at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:369)
    at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4758)
    at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4746)
    at org.glassfish.ejb.mdb.MessageBeanContainer.deliverMessage(MessageBeanContainer.java:1219)
    at org.glassfish.ejb.mdb.MessageBeanListenerImpl.deliverMessage(MessageBeanListenerImpl.java:81)
    at com.sun.enterprise.connectors.inbound.MessageEndpointInvocationHandler.invoke(MessageEndpointInvocationHandler.java:171)
    at com.sun.proxy.$Proxy511.onMessage(Unknown Source)
    at com.sun.messaging.jms.ra.OnMessageRunner.run(OnMessageRunner.java:283)
    at com.sun.enterprise.connectors.work.OneWork.doWork(OneWork.java:107)
    at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:497)
    at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:540)|#]
dorpsidioot commented 9 years ago

Renaming the deployed application's file (randomizing it) and deploying it fixes the issue. Seems the cluster isn't cleaning up certain files after undeploying.

smillidge commented 9 years ago

Is this on the latest Payara? Also do you have a simple test case or steps to reproduce as looking at the stack trace the problem is originating from an MDB?

dorpsidioot commented 9 years ago

This is on 4.1.154 release with cluster setup. This isn't happening on normal single-node setups. The current stack trace shows an MDB as origin, but this also happens when just calling a new EJB function from a rest service.

What happens is this:

It seems that in a clustered setup, the application isn't really undeployed correctly on the nodes. If I do an undeploy, and my app has @PreDestroy functions or JPA, I won't see any mentions of the predestroys being called, JPA not logging out of the entitymanager and I still see timers executing. I think this causes these strange issues.

I will try and see if I can find the time quickly to create a test application for you guys. In the meantime, I think this issue is linked to issue #492

dmatej commented 9 years ago

Timers? This is also problem for us ... I have seen some code linked with policy files in #509. Sometimes we endup with this and sometimes with "Module is in inconsistent stage". Our other applications which does not use timers have no problems with redeploys. Even on cluster.

dorpsidioot commented 9 years ago

Same here, applications without EJB timers: no issues at all, applications with them: issues all over the place, this since 4.1.154. With 4.1.153 we had intermittent issues with this. What I am seeing is that the cleanup is not done properly after undeploying on the cluster. A lot of files remain active and even timers still get executed. What I fear is that the application somehow stays in a limbo state between enabled and disabled, and keeps hogging its resources. Even when disabling, then undeploying it still keeps a certain 'state' active in memory, which could be the source of this problem. Will try to create a test case application this weekend, if my 12-weeks year old lets me work a bit ;-)

smillidge commented 9 years ago

Don't work on the weekend! Enjoy the baby.

We'll take a look at the specific case of undeploying applications with clustered EJB Timers. Are you saying this is worse in 4.1.154 or the same when compared to 4.1.153? We are currently looking at creating a Janitor service that aggressively cleans up application junk on undeploy, this will centralise all the clean up activity including application rogue classloader leaks, as best we can.

We already have a very simple EJB Timer example application here https://github.com/payara/Payara-Examples/tree/master/Java-EE/ejb-timer/simple-ejb-timer

dorpsidioot commented 9 years ago

It's definitely worse since 4.1.154. In 4.1.153 we had this issue once every 15 deploys, since 4.1154 it's with every deploy. Restarting the cluster seems to fix it when the application is in the limbo state, so I think it's a memory-based issue. The hint is in deploying apps in a cluster, then undeploying it:

When disabling the application first via the cluster screen and then undeploying:

I have checked file permissions and for testing sake the payara cluster is running as root(yes I know, bad boy) just to see if it's not linked to that.

Also: unhappy that I couldn't get to Devoxx this year, live closeby and would have loved to come and chat @ the payara booth ;-)

dorpsidioot commented 9 years ago

Another observation: when deploying a new version, adding the build number(incremental, means unique in time) causes this problem to disappear.

smillidge commented 8 years ago

Possibly related to #533 and #492 as clustered applications are not being disabled correctly although they are unloaded/

arochamo commented 8 years ago

Hit this error and tried dorpsidioot suggestions but, in my case, the only solution is to go back to 4.1.153.

smillidge commented 8 years ago

Which version of Payara?

arochamo commented 8 years ago

smillidge, I was using Payara 4.1.1.154 with 64bit Java 1.8.0_73 on SLES 12.

My situation involves a clustered Payara servers and when client send Http Post request to solution Restful service (in which call stateless session bean asynchronous method to send SMS message will cause following error:

[2016-03-17T11:09:24.086+0800] [Payara 4.1] [INFO] [] [javax.enterprise.system.core.security] [tid: _ThreadID=253 _ThreadName=__ejb-thread-pool16] [timeMillis: 1458184164086] [levelValue: 800] [[ JACC Policy Provider: Failed Permission Check, context(VrmsServer/VrmsMysqlServer-ejb_jar)- permission(("javax.security.jacc.EJBMethodPermission" "SmsMessageBean" "sendSMS,Local,java.lang.Integer,java.lang.String,java.lang.String,java.lang.String,java.lang.Integer,java.util.Date,java.lang.String,java.lang.String,java.lang.String"))]] [2016-03-17T11:09:24.089+0800] [Payara 4.1] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=253 _ThreadName=__ejb-thread-pool16] [timeMillis: 1458184164089] [levelValue: 900] [[A system exception occurred during an invocation on EJB SmsMessageBean, method: public void org.vrms.ejb.SmsMessageBean.sendSMS (java.lang.Integer,java.lang.String,java.lang.String,java.lang.String,java.lang.Integer,java.util.Date,java.lang.String,java.lang.String,java.lang.String)]] [2016-03-17T11:09:24.092+0800] [Payara 4.1] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=253 _ThreadName=__ejb-thread-pool16] [timeMillis: 1458184164092] [levelValue: 900] [[ javax.ejb.AccessLocalException: Client not authorized for this invocation at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1960) at com.sun.ejb.containers.EjbAsyncTask.call(EjbAsyncTask.java:99) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)]]

Also my solution use EJB timers for background tasks.

Same solution works fine in Payara 4.1.153

smillidge commented 8 years ago

Have you tried 161.1, the latest release?

arochamo commented 8 years ago

Not yet on 161.1 but will try later on, after releasing the solution. Tried on 161 before but due to a bug about log, my solution simply hang (keep producing logs).

smillidge commented 8 years ago

OK 161.1 fixes the log issue and likely the original issue.

arochamo commented 8 years ago

smillidge, tested on 161.1 and my previous error is fixed but notice on undeploy application, cluster instances keep application "granted.policy" file <payara home>/glassfish/nodes/<node name>/<instance name>/generated/policy/<application name>/<ejb module>_jar and <payara home>/glassfish/nodes/<node name>/<instance name>/generated/policy/<application name>/<war module>_war and these files may cause JACC permission denied error on application redeployment.

mikecroft commented 8 years ago

Hi @arochamo thanks for confirming the fix to the original issue! To keep everything clean (i.e. 1 issue = 1 bug) can you confirm that your follow up problem still exists and create a new issue for it? I'll close this issue now since it's been fixed.