Bug 1223395 - Operation [Registering Deployed Cache Store service...] happens too late on slower machines
Summary: Operation [Registering Deployed Cache Store service...] happens too late on s...
Keywords:
Status: VERIFIED
Alias: None
Product: JBoss Data Grid 6
Classification: JBoss
Component: Server
Version: 6.5.0
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ER1
: 6.5.1
Assignee: Tristan Tarrant
QA Contact: Martin Gencur
URL:
Whiteboard:
Depends On:
Blocks: 1254497
TreeView+ depends on / blocked
 
Reported: 2015-05-20 12:48 UTC by Tomas Sykora
Modified: 2023-09-30 08:28 UTC (History)
5 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
While using a deployed Custom Cache Store for a particular cache, there was a potential race condition in the JBoss Data Grid server. It was possible that the cache start-up would occur before the Custom Cache Store library registration was successfully finished, resulting in the cache being unable to find the requested resources during the start-up process and failing to start. This is not longer an issue with JDG 6.5.1
Clone Of:
: 1254497 (view as bug list)
Environment:
Last Closed:
Type: Bug
Embargoed:

Attachments (Terms of Use)
cssDeployedOKonFastMachine.txt (5.93 KB, text/plain)
2015-05-20 12:48 UTC, Tomas Sykora 		no flags Details
registeringCCSdeploymentPhaseOnSlowMachineNotOK (9.42 KB, text/plain)
2015-05-20 12:49 UTC, Tomas Sykora 		no flags Details
View All


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker ISPN-5595 0 Minor Resolved Operation [Registering Deployed Cache Store service...] happens too late on slower machines 2018-08-31 10:12:00 UTC

Description Tomas Sykora 2015-05-20 12:48:23 UTC 
Created attachment 1027710 [details]
cssDeployedOKonFastMachine.txt

This issue can't be spot on our local machines that are parforming fast enough. Usually, server is started within 4 seconds and custom cache store deployment happens fast enough so it is DONE before cache starts. 

However, on slower machines, it turned out that caches "want to" be started before this opearation finishes: 

07:19:03,721 INFO  [org.jboss.as.clustering.infinispan] (MSC service thread 1-2) JBAS010287: Registering Deployed Cache Store service for store 'org.infinispan.CustomExternalStore'

Then we can see org.infinispan.commons.CacheException: Unable to start cache loaders because there is no cache store registered YET to be picked up by cache. 

It looks like we need to make sure that caches are started really AFTER all necessary cache store deployment processes happened and are OK.

Please see 2 attached files for exact difference between starup on fast and slower machine. Find for the occurence of:

[INFO  [org.jboss.as.clustering.infinispan] (MSC service thread 1-2) JBAS010287: Registering Deployed Cache Store service for store 'org.infinispan.CustomExternalStore']

to see the difference.
Comment 1 Tomas Sykora 2015-05-20 12:49:23 UTC 
Created attachment 1027711 [details]
registeringCCSdeploymentPhaseOnSlowMachineNotOK
Comment 3 Shay Matasaro 2015-05-28 14:52:44 UTC 
14:37:24,921 ERROR [org.jboss.msc.service.fail] (MSC service thread 1-8) MSC000001: Failed to start service jboss.infinispan.local.access: org.jboss.msc.service.StartException in service jboss.infinispan.local.
access: Failed to start service
        at org.jboss.msc.service.ServiceControllerImpl$StartTask.run(ServiceControllerImpl.java:1936) [jboss-msc-1.1.5.Final-redhat-1.jar:1.1.5.Final-redhat-1]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]

14:37:25,907 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 17) JBAS015859: Deployed "infinispan-cache-store-access-1.0.0-SNAPSHOT.jar" (runtime-name : "infinispan-cache-store-access-1.0.0-SNAPSHOT.j
ar")
14:37:25,917 INFO  [org.jboss.as.controller] (Controller Boot Thread) JBAS014774: Service status report
Comment 4 Alan Field 2015-05-28 18:32:29 UTC 
Added to JDG 6.5.0 CR1
Comment 6 Tomas Sykora 2015-06-15 15:32:53 UTC 
Added doc text.
Comment 12 Sebastian Łaskawiec 2015-08-18 09:19:49 UTC 
PR: https://github.com/infinispan/jdg/pull/717
Comment 13 Tomas Sykora 2015-08-21 08:21:29 UTC 
I was able to VERIFY this issue using the same environment where it has been spot earlier. Problems does not occur again with JDG 6.5.1.ER1 version.

Thanks Sebastian for the fix!
Comment 14 JBoss JIRA Server 2015-09-15 05:48:09 UTC 
Sebastian Łaskawiec <slaskawi> updated the status of jira ISPN-5595 to Resolved
Note You need to log in before you can comment on or make changes to this bug.