Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Flaky io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest.shouldCancelAfterElementCompleted #18461

Open
deepthidevaki opened this issue May 13, 2024 · 1 comment
Open

Flaky io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest.shouldCancelAfterElementCompleted #18461

deepthidevaki opened this issue May 13, 2024 · 1 comment
Assignees
@npepinpe
Labels
component/zeebe Related to the Zeebe component/team kind/flake Categorizes issue or PR as related to a flaky test

Comments

@deepthidevaki
Copy link
Contributor

Summary

Try to answer the following as best as possible

  • How often does the test fail?
  • Does it block your work?
  • Do we suspect that it is a real failure?

Failures

Outline known failure cases, e.g. a failed assertion and its stacktrace obtained from Jenkins

shouldCancelAfterJobComplete[parallel flow] (Flaky Test): io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest
java.util.concurrent.TimeoutException: Timeout after: 15 SECONDS
	at io.camunda.zeebe.scheduler.future.CompletableActorFuture.get(CompletableActorFuture.java:137)
	at io.camunda.zeebe.scheduler.FutureUtil.join(FutureUtil.java:32)
	at io.camunda.zeebe.scheduler.future.CompletableActorFuture.join(CompletableActorFuture.java:208)
	at io.camunda.zeebe.engine.util.TestStreams.buildStreamProcessor(TestStreams.java:275)
	at io.camunda.zeebe.engine.util.TestStreams.startStreamProcessor(TestStreams.java:218)
	at io.camunda.zeebe.engine.util.StreamProcessingComposite.startTypedStreamProcessor(StreamProcessingComposite.java:92)
	at io.camunda.zeebe.engine.util.StreamProcessorRule.startTypedStreamProcessor(StreamProcessorRule.java:141)
	at io.camunda.zeebe.engine.util.EngineRule.lambda$startProcessors$3(EngineRule.java:168)
	at io.camunda.zeebe.engine.util.EngineRule.forEachPartition(EngineRule.java:202)
	at io.camunda.zeebe.engine.util.EngineRule.startProcessors(EngineRule.java:163)
	at io.camunda.zeebe.engine.util.EngineRule.start(EngineRule.java:128)
	at io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest.shouldCancelAfterJobComplete(CancelProcessInstanceConcurrentlyTest.java:176)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)

shouldCancelAfterElementCompleting[sub-process] (Flaky Test): io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest
java.util.concurrent.ExecutionException: Actor is closed
	at io.camunda.zeebe.scheduler.future.CompletableActorFuture.get(CompletableActorFuture.java:147)
	at io.camunda.zeebe.scheduler.future.CompletableActorFuture.get(CompletableActorFuture.java:114)
	at io.camunda.zeebe.scheduler.FutureUtil.join(FutureUtil.java:21)
	at io.camunda.zeebe.scheduler.future.CompletableActorFuture.join(CompletableActorFuture.java:203)
	at io.camunda.zeebe.logstreams.util.SyncLogStream.newLogStreamWriter(SyncLogStream.java:77)
	at io.camunda.zeebe.engine.util.TestStreams$LogContext.newLogStreamWriter(TestStreams.java:430)
	at io.camunda.zeebe.engine.util.TestStreams.newLogStreamWriter(TestStreams.java:170)
	at io.camunda.zeebe.engine.util.TestStreams.newRecord(TestStreams.java:187)
	at io.camunda.zeebe.engine.util.StreamProcessingComposite.writeCommand(StreamProcessingComposite.java:154)
	at io.camunda.zeebe.engine.util.StreamProcessingComposite.writeCommand(StreamProcessingComposite.java:146)
	at io.camunda.zeebe.engine.util.StreamProcessorRule.writeCommand(StreamProcessorRule.java:195)
	at io.camunda.zeebe.engine.util.client.DeploymentClient.deploy(DeploymentClient.java:174)
	at io.camunda.zeebe.engine.processing.processinstance.CancelProcessInstanceConcurrentlyTest.init(CancelProcessInstanceConcurrentlyTest.java:131)
	at java.base/java.lang.reflect.Method.invoke(Method.java:580)
Caused by: java.lang.RuntimeException: Actor is closed
	at io.camunda.zeebe.logstreams.impl.log.LogStreamImpl.newLogStreamWriter(LogStreamImpl.java:156)
	... 10 more

Hypotheses

Logs
https://github.com/camunda/zeebe/actions/runs/9063172403

Test results for unit tests.zip
@deepthidevaki deepthidevaki added kind/flake Categorizes issue or PR as related to a flaky test component/zeebe Related to the Zeebe component/team labels May 13, 2024
@mustafadagher
Copy link
Contributor

mustafadagher commented May 29, 2024 •
edited

I couldn't reproduce this locally, but inspecting the logs from the test results, below is a complete stacktrace of the errors.

It seems from the logs that the actor was closed and it was failing to start again. I see also several NullPointerExceptions for logStreamReader and asyncActor being null.

I'm not sure, but I feel like someone from @camunda/zeebe-distributed-platform should have a look at this too.

Logs 
12:54:28.213 [LogStream-1] ERROR io.camunda.zeebe.logstreams - Unexpected error in Log Stream LogStream-1 in phase STARTED.
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@45a75521[Not completed, task = java.util.concurrent.Executors$RunnableAdapter@35e5cd8e[Wrapped task = io.camunda.zeebe.engine.util.ProcessingExporterTransistor$$Lambda/0x00007cecf0718800@6753ae3f]] rejected from java.util.concurrent.ThreadPoolExecutor@2b9cc193[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 5]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2081) ~[?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:841) ~[?:?]
	at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1371) ~[?:?]
	at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123) ~[?:?]
	at java.base/java.util.concurrent.Executors$DelegatedExecutorService.submit(Executors.java:785) ~[?:?]
	at io.camunda.zeebe.engine.util.ProcessingExporterTransistor.onNewEventCommitted(ProcessingExporterTransistor.java:66) ~[test-classes/:?]
	at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[?:?]
	at io.camunda.zeebe.logstreams.impl.log.LogStreamImpl.notifyRecordAwaiters(LogStreamImpl.java:184) ~[zeebe-logstreams-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorControl.lambda$call$0(ActorControl.java:75) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.invoke(ActorJob.java:88) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.execute(ActorJob.java:47) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.execute(ActorTask.java:122) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.executeCurrentTask(ActorThread.java:130) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.doWork(ActorThread.java:108) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.run(ActorThread.java:227) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
12:54:28.231 [LogStream-1] INFO  io.camunda.zeebe.logstreams - On closing logstream stream-1 close 16 readers
12:54:28.299 [StreamProcessor-1] ERROR io.camunda.zeebe.logstreams - Unexpected error on retrieving reader from log stream.
java.lang.RuntimeException: Actor is closed
	at io.camunda.zeebe.scheduler.ActorJob.failFuture(ActorJob.java:172) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ClosedQueue.offer(ClosedQueue.java:84) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ClosedQueue.offer(ClosedQueue.java:15) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.submit(ActorTask.java:102) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorControl.call(ActorControl.java:172) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.logstreams.impl.log.LogStreamImpl.newLogStreamReader(LogStreamImpl.java:149) ~[zeebe-logstreams-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.stream.impl.StreamProcessor.onActorStarting(StreamProcessor.java:155) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.invoke(ActorJob.java:94) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.execute(ActorJob.java:47) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.execute(ActorTask.java:122) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.executeCurrentTask(ActorThread.java:130) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.doWork(ActorThread.java:108) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.run(ActorThread.java:227) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
12:54:28.307 [StreamProcessor-1] DEBUG io.camunda.zeebe.logstreams - Recovering state of partition 1 from snapshot
12:54:28.307 [StreamProcessor-1] ERROR io.camunda.zeebe.logstreams - Actor StreamProcessor-1 failed in phase STARTED.
java.lang.NullPointerException: Cannot invoke "io.camunda.zeebe.logstreams.log.LogStreamReader.seekToNextEvent(long)" because "this.logStreamReader" is null
	at io.camunda.zeebe.stream.impl.StreamProcessor.recoverFromSnapshot(StreamProcessor.java:402) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.stream.impl.StreamProcessor.onActorStarted(StreamProcessor.java:163) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.invoke(ActorJob.java:94) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.execute(ActorJob.java:47) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.execute(ActorTask.java:122) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.executeCurrentTask(ActorThread.java:130) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.doWork(ActorThread.java:108) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.run(ActorThread.java:227) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
12:54:28.307 [StreamProcessor-1] ERROR io.camunda.zeebe.logstreams - Actor StreamProcessor-1 failed in phase STARTED.
java.lang.NullPointerException: Cannot invoke "io.camunda.zeebe.stream.impl.StreamProcessor$AsyncProcessingScheduleServiceActor.closeAsync()" because "this.asyncActor" is null
	at io.camunda.zeebe.stream.impl.StreamProcessor.onFailure(StreamProcessor.java:428) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.stream.impl.StreamProcessor.onActorStarted(StreamProcessor.java:228) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.invoke(ActorJob.java:94) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.execute(ActorJob.java:47) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.execute(ActorTask.java:122) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.executeCurrentTask(ActorThread.java:130) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.doWork(ActorThread.java:108) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.run(ActorThread.java:227) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
12:54:28.310 [StreamProcessor-1] ERROR io.camunda.zeebe.util.actor - Unexpected error occurred in task StreamProcessor-1 ACTIVE phase: STARTED
java.lang.NullPointerException: Cannot invoke "io.camunda.zeebe.stream.impl.StreamProcessor$AsyncProcessingScheduleServiceActor.closeAsync()" because "this.asyncActor" is null
	at io.camunda.zeebe.stream.impl.StreamProcessor.onFailure(StreamProcessor.java:428) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.stream.impl.StreamProcessor.handleFailure(StreamProcessor.java:261) ~[zeebe-stream-platform-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.onFailure(ActorTask.java:301) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorJob.execute(ActorJob.java:56) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorTask.execute(ActorTask.java:122) ~[zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.executeCurrentTask(ActorThread.java:130) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.doWork(ActorThread.java:108) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]
	at io.camunda.zeebe.scheduler.ActorThread.run(ActorThread.java:227) [zeebe-scheduler-8.6.0-SNAPSHOT.jar:8.6.0-SNAPSHOT]

@mustafadagher mustafadagher removed their assignment May 29, 2024
@npepinpe npepinpe self-assigned this May 30, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@npepinpe npepinpe

Labels
component/zeebe Related to the Zeebe component/team kind/flake Categorizes issue or PR as related to a flaky test
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@npepinpe @deepthidevaki @mustafadagher