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
880 stars 301 forks source link

Bug Report: Clustered singleton scheduler cause CP subsystem WrongTargetException exception #5545

Closed cidylong closed 2 years ago

cidylong commented 2 years ago

Description

I'm trying to make a simple Clustered Singleton to generate a simple TextMessage and put in message queue (queue configured and it works fine). This message pusher is working fine if I don't annotated it as @Clustered, as result, very Payara Application server will generate a TextMessage and put it in my Queue.

@Clustered(callPostConstructOnAttach = false, callPreDestoyOnDetach = false, keyName = "singletonClusteredMsgPusherEJB", lock = DistributedLockType.LOCK_NONE) @Singleton public class MsgPusher implements Serializable { private static final ILogger logger = Logger.getLogger(MsgPusher.class.getName());

@Resource(lookup = "jms/thssConnectionFactory")
private ConnectionFactory jmsFactory;

@Resource(lookup = "jms/thssQueue")
private Queue jmsQueue;

private String[] stockCodes = { "MSFT", "GOOGL", "AAPL", "AMZN" };

@Schedule(minute = "*/30", hour = "*", persistent = false)
public void sendStockInformation() {

    TextMessage message;

    try (Connection connection = jmsFactory.createConnection();
         Session session = connection.createSession(false, Session.AUTO_ACKNOWLEDGE);
         MessageProducer producer = session.createProducer(jmsQueue)) {

        JsonObject stockInformation = Json.createObjectBuilder()
                .add("stockCode", stockCodes[ThreadLocalRandom.current().nextInt(stockCodes.length)])
                .add("price", ThreadLocalRandom.current().nextDouble(1.0, 150.0))
                .add("timestamp", Instant.now().toEpochMilli()).build();

        message = session.createTextMessage();
        message.setText(stockInformation.toString());
        logger.info("Stock information will be put into message queue. "+stockInformation.toString());
        producer.send(message);

    } catch (JMSException e) {
        e.printStackTrace();
    }
}

}

My Payara Hazelcast configure for CP-Subsystem as:

7 3 300 5 14400 false 2000 5000 5 100 10000 100 100

When I deploy the Application Jar file into deployment group (APPDG), deployment is fine, but when scheduler fired on pre-defined timer,

Expected Outcome

Expected there is only one EJB instance will be fired on one of two Payara application servers (ThssEJBServer, ThssWEBServer) in a deployment group (APPDG).

Current Outcome

CP-Subsystem throws WrongTargetException:

[2021-12-24T09:31:22.130+1100] [Payara 5.2021.5] [WARNING] [] [com.hazelcast.spi.impl.operationservice.impl.Invocation] [tid: _ThreadID=79 _ThreadName=hz.condescending_lamarr.InvocationMonitorThread] [timeMillis: 1640298682130] [levelValue: 900] [[ [10.0.1.102]:5702 [thss] [4.2] Retrying invocation: Invocation{op=com.hazelcast.cp.internal.operation.RaftQueryOp{serviceName='hz:core:raft', identityHash=1537212326, partitionId=0, replicaIndex=0, callId=235115, invocationTime=1640298682130 (2021-12-24 09:31:22.130), waitTimeout=-1, callTimeout=60000, tenantControl=com.hazelcast.spi.impl.tenantcontrol.NoopTenantControl@0, op=com.hazelcast.cp.internal.raftop.metadata.GetActiveRaftGroupByNameOp{serviceName='hz:core:raft', groupName=default}, groupId=CPGroupId{name='METADATA', seed=0, groupId=0}, policy=LINEARIZABLE}, tryCount=250, tryPauseMillis=500, invokeCount=240, callTimeoutMillis=60000, firstInvocationTimeMs=1640298600004, firstInvocationTime='2021-12-24 09:30:00.004', lastHeartbeatMillis=0, lastHeartbeatTime='1970-01-01 10:00:00.000', target=null, pendingResponse={VOID}, backupsAcksExpected=-1, backupsAcksReceived=0, connection=null}, Reason: com.hazelcast.spi.exception.WrongTargetException: WrongTarget! local: Member [10.0.1.102]:5702 - 52a1c67f-c702-483d-8d76-d6ee4841fc06 this, expected-target: null, partitionId: 0, replicaIndex: 0, operation: com.hazelcast.cp.internal.operation.RaftQueryOp, service: hz:core:raft]]

[2021-12-24T09:31:27.133+1100] [Payara 5.2021.5] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=423 _ThreadName=__ejb-thread-pool6] [timeMillis: 1640298687133] [levelValue: 900] [[ A system exception occurred during an invocation on EJB MsgPusher, method: public void com.longz.thss.ejb.scheduler.MsgPusher.sendStockInformation()]]

[2021-12-24T09:31:27.133+1100] [Payara 5.2021.5] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=423 _ThreadName=__ejb-thread-pool6] [timeMillis: 1640298687133] [levelValue: 900] [[

javax.ejb.EJBException: javax.ejb.CreateException: Initialization failed for Singleton MsgPusher at com.sun.ejb.containers.AbstractSingletonContainer$SingletonContextFactory.create(AbstractSingletonContainer.java:689) at com.sun.ejb.containers.AbstractSingletonContainer.instantiateSingletonInstance(AbstractSingletonContainer.java:421) at org.glassfish.ejb.startup.SingletonLifeCycleManager.initializeSingleton(SingletonLifeCycleManager.java:219) at org.glassfish.ejb.startup.SingletonLifeCycleManager.initializeSingleton(SingletonLifeCycleManager.java:180) at com.sun.ejb.containers.AbstractSingletonContainer.checkInit(AbstractSingletonContainer.java:395) at com.sun.ejb.containers.AbstractSingletonContainer._getContext(AbstractSingletonContainer.java:185) at com.sun.ejb.containers.CMCSingletonContainer._getContext(CMCSingletonContainer.java:120) at com.sun.ejb.containers.BaseContainer.getContext(BaseContainer.java:2598) at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:2019) at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4033) at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1208) at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:96) at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1937) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: javax.ejb.CreateException: Initialization failed for Singleton MsgPusher at com.sun.ejb.containers.AbstractSingletonContainer.createSingletonEJB(AbstractSingletonContainer.java:542) at com.sun.ejb.containers.AbstractSingletonContainer.access$000(AbstractSingletonContainer.java:81) at com.sun.ejb.containers.AbstractSingletonContainer$SingletonContextFactory.create(AbstractSingletonContainer.java:687) ... 17 more Caused by: com.hazelcast.spi.exception.WrongTargetException: WrongTarget! local: Member [10.0.1.102]:5702 - 52a1c67f-c702-483d-8d76-d6ee4841fc06 this, expected-target: null, partitionId: 0, replicaIndex: 0, operation: com.hazelcast.cp.internal.operation.RaftQueryOp, service: hz:core:raft at com.hazelcast.spi.impl.operationservice.impl.Invocation.newTargetNullException(Invocation.java:317) at com.hazelcast.spi.impl.operationservice.impl.Invocation.initInvocationTarget(Invocation.java:272) at com.hazelcast.spi.impl.operationservice.impl.Invocation.doInvoke(Invocation.java:562) at com.hazelcast.spi.impl.operationservice.impl.Invocation.access$400(Invocation.java:100) at com.hazelcast.spi.impl.operationservice.impl.Invocation$InvocationRetryTask.run(Invocation.java:804) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) at ------ submitted from ------.() at com.hazelcast.internal.util.ExceptionUtil.cloneExceptionWithFixedAsyncStackTrace(ExceptionUtil.java:279) at com.hazelcast.spi.impl.AbstractInvocationFuture.wrapRuntimeException(AbstractInvocationFuture.java:1968) at com.hazelcast.spi.impl.AbstractInvocationFuture.wrapOrPeel(AbstractInvocationFuture.java:1949) at com.hazelcast.spi.impl.AbstractInvocationFuture$ExceptionalResult.wrapForJoinInternal(AbstractInvocationFuture.java:1431) at com.hazelcast.spi.impl.AbstractInvocationFuture.resolveAndThrowForJoinInternal(AbstractInvocationFuture.java:600) at com.hazelcast.spi.impl.AbstractInvocationFuture.joinInternal(AbstractInvocationFuture.java:584) at com.hazelcast.cp.internal.RaftService.createRaftGroupForProxy(RaftService.java:970) at com.hazelcast.cp.internal.datastructures.spi.atomic.RaftAtomicValueService.createProxy(RaftAtomicValueService.java:172) at com.hazelcast.cp.internal.CPSubsystemImpl.createProxy(CPSubsystemImpl.java:143) at com.hazelcast.cp.internal.CPSubsystemImpl.getAtomicLong(CPSubsystemImpl.java:78) at com.sun.enterprise.container.common.impl.util.ClusteredSingletonLookupImplBase.lambda$getClusteredUsageCount$2(ClusteredSingletonLookupImplBase.java:108) at java.base/java.util.concurrent.atomic.AtomicReference.updateAndGet(AtomicReference.java:209) at com.sun.enterprise.container.common.impl.util.ClusteredSingletonLookupImplBase.getClusteredUsageCount(ClusteredSingletonLookupImplBase.java:107) at com.sun.ejb.containers.AbstractSingletonContainer.createSingletonEJB(AbstractSingletonContainer.java:485) ... 19 more ]]

[2021-12-24T09:31:32.134+1100] [Payara 5.2021.5] [WARNING] [AS-EJB-00056] [javax.enterprise.ejb.container] [tid: _ThreadID=426 _ThreadName=__ejb-thread-pool7] [timeMillis: 1640298692134] [levelValue: 900] [[ A system exception occurred during an invocation on EJB MsgPusher, method: public void com.longz.thss.ejb.scheduler.MsgPusher.sendStockInformation()]]

[2021-12-24T09:31:32.134+1100] [Payara 5.2021.5] [WARNING] [] [javax.enterprise.ejb.container] [tid: _ThreadID=426 _ThreadName=__ejb-thread-pool7] [timeMillis: 1640298692134] [levelValue: 900] [[

javax.ejb.NoSuchEJBException: Singleton MsgPusher is unavailable because its original initialization failed. at com.sun.ejb.containers.AbstractSingletonContainer.checkInit(AbstractSingletonContainer.java:386) at com.sun.ejb.containers.AbstractSingletonContainer._getContext(AbstractSingletonContainer.java:185) at com.sun.ejb.containers.CMCSingletonContainer._getContext(CMCSingletonContainer.java:120) at com.sun.ejb.containers.BaseContainer.getContext(BaseContainer.java:2598) at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:2019) at com.sun.ejb.containers.BaseContainer.callEJBTimeout(BaseContainer.java:4033) at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1208) at com.sun.ejb.containers.EJBTimerService.access$000(EJBTimerService.java:96) at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:1937) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:834) ]]

[2021-12-24T09:31:32.134+1100] [Payara 5.2021.5] [INFO] [] [javax.enterprise.system.container.ejb.com.sun.ejb.containers] [tid: _ThreadID=426 _ThreadName=__ejb-thread-pool7] [timeMillis: 1640298692134] [levelValue: 800] [[ EJB5119:Expunging timer ['2@@1640296713118@@ThssEJBServer@@ThssEJBServer' 'TimedObject = MsgPusher' 'Application = EJBModule' 'BEING_DELIVERED' 'PERIODIC' 'Container ID = 107492719484979078' 'Fri Dec 24 09:30:00 AEDT 2021' '0' '0 # /30 # # # # # # null # null # null # true # sendStockInformation # 0' ] after [2] failed deliveries]]

Steps to reproduce

  1. Configure Hazelcast with CP-Subsystem,
  2. At least two Payara application servers in a single deployment group.
  3. Develop a simple Clustered Singleton Scheduler EJB to do some thing
  4. Compile and deploy it into a deployment group
  5. Check server logs

Environment

Payara Community version version: 5.2021.5, Two Payara application servers(ThssEJBServer, ThssWEBServer) in a deployment group (APPDG) that runs on different nodes (IP: 10.0.1.102,10.0.1.152), Server Operating system: Centos 8 (Linux) JDK version: 11.0.9 (Oracle)

cidylong commented 2 years ago
7 3 300 5 14400 false 2000 5000 5 100 10000 100 100
cidylong commented 2 years ago

Your bug report system seems not support XML format configure?

lprimak commented 2 years ago

This is a Hazelcast error. I am not sure why you are getting it. Please check Hazelcast documentation and your configuration

lprimak commented 2 years ago

Also, @Scheduled should only produce one invocation per cluster regardless if it's @Clustered or not. You are setting persistent = false which disables that functionality. If you leave persistent = true (the default) you will have one invocation per deployment group, regardless if the bean is clustered or not.

cidylong commented 2 years ago

@lprimak ,configure out cp-subsystem by setting cp-member-number and group-size to 0, restart domain, error message gone, but there are two schedulers instances were created by two Payara Application servers (seems @Singleton annotation not working).

cidylong commented 2 years ago

@lprimak ,yeah, @Scheduled method was annotated as persistent = false. I will try to set it to true.

fturizo commented 2 years ago

@cidylong, as @lprimak noted, in the context of this scenario, there's no need to use the @Clustered annotation, as persistent EJB timers are executed only once in the cluster as per the specification.

Additionally, as the default configuration of Payara Server's is to run the CP subsystem in un-safe mode, we consider turning it on safe mode only a necessity for production environments, which unfortunately is not a use case we support in the Community Edition. If you require support on this specific feature of the Payara Server + Hazelcast integration, we do recommend acquiring a Payara Enterprise license which will cover support on this requirement in more detail. If you require further assistance on how to properly configure this feature on Payara Server, please raise a new topic on the official Payara Forum.

cidylong commented 2 years ago

Thank you!

Please update it into documentation.

On Thu, Dec 30, 2021 at 8:01 AM Fabio Turizo @.***> wrote:

Closed #5545 https://github.com/payara/Payara/issues/5545.

— Reply to this email directly, view it on GitHub https://github.com/payara/Payara/issues/5545#event-5826060742, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACVHLGUI3STN6HXA7YVRZ53UTNZJZANCNFSM5KXSQWUA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>