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

Scheduled tasks may not run in clustered environments #9079

Closed
rymsha opened this issue Sep 16, 2021 · 2 comments
Closed

Scheduled tasks may not run in clustered environments #9079

rymsha opened this issue Sep 16, 2021 · 2 comments
Assignees
@rymsha
Labels
Bug
Projects
Bugs
Milestone
7.7.3

Comments

@rymsha
Copy link
Contributor

rymsha commented Sep 16, 2021

#9048 was certainly fixed
But we still observe a similar condition from time to time.
@rymsha rymsha added the Bug label Sep 16, 2021
@rymsha rymsha self-assigned this Sep 16, 2021
@rymsha rymsha added this to Needs triage in Bugs via automation Sep 16, 2021
@rymsha
Copy link
Contributor Author

rymsha commented Sep 16, 2021

Final logs:

2021-09-16 11:54:20,242 INFO  E.S.com.enonic.xp.core.elasticsearch - ServiceEvent REGISTERED [org.elasticsearch.node.Node]
2021-09-16 11:54:20,247 INFO  E.S.com.enonic.xp.core.elasticsearch - ServiceEvent REGISTERED [org.elasticsearch.cluster.ClusterService]
2021-09-16 11:54:20,253 INFO  E.S.com.enonic.xp.core.elasticsearch - ServiceEvent REGISTERED [org.elasticsearch.transport.TransportService]
2021-09-16 11:54:20,257 INFO  E.S.com.enonic.xp.core.elasticsearch - ServiceEvent REGISTERED [org.elasticsearch.client.Client]
2021-09-16 11:54:20,263 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.index.IndexServiceInternal]
2021-09-16 11:54:20,265 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repository.NodeRepositoryService]
2021-09-16 11:54:20,295 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.search.SearchDao]
2021-09-16 11:54:20,300 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.search.NodeSearchService]
2021-09-16 11:54:20,307 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.storage.StorageDao]
2021-09-16 11:54:20,309 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.branch.BranchService]
2021-09-16 11:54:20,311 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.commit.CommitService]
2021-09-16 11:54:20,317 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.storage.IndexDataService]
2021-09-16 11:54:20,321 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.version.VersionService]
2021-09-16 11:54:20,325 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.storage.NodeStorageService]
2021-09-16 11:54:20,332 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.event.EventListener]
2021-09-16 11:54:20,572 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.repo.impl.repository.RepositoryEntryService]
2021-09-16 11:54:20,574 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.snapshot.SnapshotService]
2021-09-16 11:54:20,619 INFO  E.Service.com.enonic.xp.server.rest - ServiceEvent REGISTERED [com.enonic.xp.jaxrs.JaxRsComponent]
2021-09-16 11:54:20,643 INFO  E.Service.com.enonic.xp.admin.impl - ServiceEvent REGISTERED [com.enonic.xp.jaxrs.JaxRsComponent]
2021-09-16 11:54:20,645 INFO  E.Service.com.enonic.xp.core.repo - ServiceEvent REGISTERED [com.enonic.xp.index.IndexService]
2021-09-16 11:54:20,646 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : dm $001 tracking 2 SingleStatic added [com.enonic.xp.index.IndexService] (enter)
2021-09-16 11:54:20,648 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : ActivateInternal
2021-09-16 11:54:20,648 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Querying state unsatisfiedReference
2021-09-16 11:54:20,650 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Querying state unsatisfiedReference
2021-09-16 11:54:20,651 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Activating component from state unsatisfiedReference
2021-09-16 11:54:20,652 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Querying state unsatisfiedReference
2021-09-16 11:54:20,653 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Querying state unsatisfiedReference
2021-09-16 11:54:20,654 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Dependency not satisfied: $000
2021-09-16 11:54:20,655 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Dependency not satisfied: $002
2021-09-16 11:54:20,656 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Dependency not satisfied: $004
2021-09-16 11:54:20,657 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Dependency not satisfied: $005
2021-09-16 11:54:20,659 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : Not all dependencies satisfied, cannot activate
2021-09-16 11:54:20,660 DEBUG c.e.x.i.s.SchedulerServiceActivator - bundle com.enonic.xp.core.scheduler:7.7.3.RC1 (68)[com.enonic.xp.impl.scheduler.SchedulerServiceActivator(127)] : dm $001 tracking 2 SingleStatic added [com.enonic.xp.index.IndexService] (exit)

What is interesting here is that SchedulerServiceActivator never gets started

In such state rescheduling never can be done

2021-09-16 11:54:23,872 WARN  c.e.x.i.s.distributed.RescheduleTask - Problem during tasks scheduling
java.lang.IllegalStateException: No service found interface com.enonic.xp.scheduler.SchedulerService
	at com.enonic.xp.core.internal.osgi.OsgiSupport.lambda$withService$3(OsgiSupport.java:97)
	at com.enonic.xp.core.internal.osgi.OsgiSupport.withServiceOrElseGet(OsgiSupport.java:59)
	at com.enonic.xp.core.internal.osgi.OsgiSupport.withService(OsgiSupport.java:96)
	at com.enonic.xp.impl.scheduler.distributed.RescheduleTask.doRun(RescheduleTask.java:69)
	at com.enonic.xp.impl.scheduler.distributed.RescheduleTask.run(RescheduleTask.java:47)
	at com.hazelcast.scheduledexecutor.impl.ScheduledRunnableAdapter.call(ScheduledRunnableAdapter.java:56)
	at com.hazelcast.scheduledexecutor.impl.TaskRunner.call(TaskRunner.java:63)
	at com.hazelcast.scheduledexecutor.impl.TaskRunner.run(TaskRunner.java:80)
	at com.hazelcast.spi.impl.executionservice.impl.DelegateAndSkipOnConcurrentExecutionDecorator$DelegateDecorator.run(DelegateAndSkipOnConcurrentExecutionDecorator.java:77)
	at com.hazelcast.util.executor.CachedExecutorServiceDelegate$Worker.run(CachedExecutorServiceDelegate.java:227)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
	at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:64)
	at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:80)

So, it looks like a Felix Framework bug

rymsha added a commit that referenced this issue Sep 16, 2021
@rymsha
Scheduled tasks may not run on clustered environments (take2) #9079
0903a69
@rymsha
Copy link
Contributor Author

rymsha commented Sep 16, 2021 •
edited

Let's update felix SCR module
It may fix he problem apache/felix-dev@cf2cf3c

rymsha added a commit that referenced this issue Sep 16, 2021
@rymsha
Scheduled tasks may not run on clustered environments (take2) #9079
619ae9d
rymsha added a commit that referenced this issue Sep 16, 2021
@rymsha
Scheduled tasks may not run on clustered environments (take2) #9079
58085f1
rymsha added a commit that referenced this issue Sep 16, 2021
@rymsha
Scheduled tasks may not run on clustered environments (take2) #9079
b4ab61c
@rymsha rymsha added this to the 7.7.3 milestone Sep 20, 2021
@rymsha rymsha moved this from Needs triage to Closed in Bugs Sep 20, 2021
@alansemenov alansemenov changed the title Scheduled tasks may not run on clustered environments (take2) Scheduled tasks may not run on clustered environments Nov 5, 2021
@alansemenov alansemenov changed the title Scheduled tasks may not run on clustered environments Scheduled tasks may not run in clustered environments Nov 5, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rymsha rymsha

Labels
Bug
Projects
No open projects
Bugs
Closed
Milestone
7.7.3
Development

No branches or pull requests
2 participants
@rymsha @alansemenov