Restore operation does not end
folch Feb 3, 2016 10:22 AMHi,
We are trying to do an upgrade from Modesahpe 3.8.1 to Modeshape 4.4.0 and we are using the backup/restore API to migrate all the content.
The backup process suceeds in just 2 minutes (backup folder has 650Mb).
The main problem is the restore operation in Modeshape 4.4.0 because it seems never ends (stopped after 8h) and there are not messages in the log appart of "INFO: Running ModeShape 4.0.0.Alpha1 upgrade function..."
The CPU is working (around 86%) and the Java memory is almost full (2Gb).
Infinispan is configured with a JDBC DB (H2 in File System), however we are also doing tests with other DBs.
If I do a Stacktrace I can see the following threads
"persistence-thread--p12-t1" daemon prio=6 tid=0x0000000010f4d000 nid=0x1ce4 runnable [0x0000000015d6e000]
java.lang.Thread.State: RUNNABLE
at java.io.RandomAccessFile.seek(Native Method)
at org.h2.store.fs.FileDisk.position(FilePathDisk.java:461)
at org.h2.store.FileStore.seek(FileStore.java:294)
at org.h2.store.PageStore.readPage(PageStore.java:1325)
at org.h2.store.PageStore.getPage(PageStore.java:750)
- locked <0x0000000780fa4de0> (a org.h2.store.PageStore)
at org.h2.index.PageDataIndex.getPage(PageDataIndex.java:234)
at org.h2.index.PageDataNode.getNextPage(PageDataNode.java:233)
at org.h2.index.PageDataLeaf.getNextPage(PageDataLeaf.java:400)
at org.h2.index.PageDataCursor.nextRow(PageDataCursor.java:95)
at org.h2.index.PageDataCursor.next(PageDataCursor.java:53)
at org.h2.index.IndexCursor.next(IndexCursor.java:278)
at org.h2.table.TableFilter.next(TableFilter.java:361)
at org.h2.command.dml.Delete.update(Delete.java:71)
at org.h2.command.CommandContainer.update(CommandContainer.java:79)
at org.h2.command.Command.executeUpdate(Command.java:254)
- locked <0x0000000780f9be60> (a org.h2.engine.Database)
at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:158)
- locked <0x00000007815e7a10> (a org.h2.engine.Session)
at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPreparedStatement.java:144)
at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore$1.call(JdbcStringBasedStore.java:282)
at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore$1.call(JdbcStringBasedStore.java:272)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
"http-bio-9090-exec-1" daemon prio=6 tid=0x0000000010f4b000 nid=0x2530 waiting for monitor entry [0x000000001b4ec000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.h2.command.Command.executeQuery(Command.java:191)
- waiting to lock <0x0000000780f9be60> (a org.h2.engine.Database)
at org.h2.jdbc.JdbcPreparedStatement.executeQuery(JdbcPreparedStatement.java:109)
- locked <0x00000007815dabe0> (a org.h2.engine.Session)
at org.infinispan.persistence.jdbc.stringbased.JdbcStringBasedStore.load(JdbcStringBasedStore.java:201)
at org.infinispan.persistence.manager.PersistenceManagerImpl.loadFromAllStores(PersistenceManagerImpl.java:436)
at org.infinispan.persistence.PersistenceUtil.loadAndCheckExpiration(PersistenceUtil.java:116)
at org.infinispan.persistence.PersistenceUtil$4.compute(PersistenceUtil.java:100)
at org.infinispan.container.DefaultDataContainer$BoundedEquivalentConcurrentExtendedMap$2.apply(DefaultDataContainer.java:539)
at org.infinispan.container.DefaultDataContainer$BoundedEquivalentConcurrentExtendedMap$2.apply(DefaultDataContainer.java:536)
at org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8.compute(BoundedEquivalentConcurrentHashMapV8.java:3430)
- locked <0x0000000782620330> (a org.infinispan.commons.util.concurrent.jdk8backported.BoundedEquivalentConcurrentHashMapV8$Node)
at org.infinispan.container.DefaultDataContainer$BoundedEquivalentConcurrentExtendedMap.compute(DefaultDataContainer.java:535)
at org.infinispan.container.DefaultDataContainer.compute(DefaultDataContainer.java:255)
at org.infinispan.persistence.PersistenceUtil.loadAndStoreInDataContainer(PersistenceUtil.java:90)
at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:216)
at org.infinispan.interceptors.CacheLoaderInterceptor.visitDataCommand(CacheLoaderInterceptor.java:147)
at org.infinispan.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:101)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.EntryWrappingInterceptor.visitDataReadCommand(EntryWrappingInterceptor.java:130)
at org.infinispan.interceptors.EntryWrappingInterceptor.visitGetKeyValueCommand(EntryWrappingInterceptor.java:120)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitDataReadCommand(OptimisticLockingInterceptor.java:98)
at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitGetKeyValueCommand(AbstractLockingInterceptor.java:70)
at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitGetKeyValueCommand(OptimisticLockingInterceptor.java:109)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)
at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:346)
at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:318)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.CacheMgmtInterceptor.visitDataReadCommand(CacheMgmtInterceptor.java:103)
at org.infinispan.interceptors.CacheMgmtInterceptor.visitGetKeyValueCommand(CacheMgmtInterceptor.java:91)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)
at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102)
at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:71)
at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:86)
at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:40)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)
at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:430)
at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:422)
at org.infinispan.schematic.internal.CacheSchematicDb.get(CacheSchematicDb.java:77)
at org.modeshape.jcr.cache.document.LocalDocumentStore.get(LocalDocumentStore.java:71)
at org.modeshape.jcr.cache.document.WorkspaceCache.documentFor(WorkspaceCache.java:188)
at org.modeshape.jcr.cache.document.WorkspaceCache.documentFor(WorkspaceCache.java:207)
at org.modeshape.jcr.cache.document.WorkspaceCache.getNode(WorkspaceCache.java:239)
at org.modeshape.jcr.cache.document.NodeCacheIterator.nextNode(NodeCacheIterator.java:103)
at org.modeshape.jcr.cache.document.NodeCacheIterator.hasNext(NodeCacheIterator.java:70)
at org.modeshape.jcr.query.NodeSequence$16.hasNext(NodeSequence.java:1450)
at org.modeshape.jcr.query.NodeSequence$23.findNext(NodeSequence.java:1863)
at org.modeshape.jcr.query.NodeSequence$23.hasNext(NodeSequence.java:1849)
at org.modeshape.jcr.query.NodeSequence$23.findNext(NodeSequence.java:1863)
at org.modeshape.jcr.query.NodeSequence$23.hasNext(NodeSequence.java:1849)
at org.modeshape.jcr.query.NodeSequence$SingleWidthBatch.<init>(NodeSequence.java:1920)
at org.modeshape.jcr.query.NodeSequence.copy(NodeSequence.java:1907)
at org.modeshape.jcr.query.engine.process.RestartableSequence.loadBatch(RestartableSequence.java:213)
at org.modeshape.jcr.query.engine.process.RestartableSequence.loadRemaining(RestartableSequence.java:188)
at org.modeshape.jcr.query.engine.process.RestartableSequence.getRowCount(RestartableSequence.java:107)
at org.modeshape.jcr.query.JcrQueryResult$QueryResultIterator.getSize(JcrQueryResult.java:275)
at org.modeshape.jcr.Upgrades$ModeShape_4_0_0_Alpha1.apply(Upgrades.java:266)
at org.modeshape.jcr.Upgrades.applyUpgradesSince(Upgrades.java:98)
at org.modeshape.jcr.cache.RepositoryCache$4.call(RepositoryCache.java:474)
at org.modeshape.jcr.cache.RepositoryCache$4.call(RepositoryCache.java:469)
at org.modeshape.jcr.cache.RepositoryCache.runInTransaction(RepositoryCache.java:516)
at org.modeshape.jcr.cache.RepositoryCache.completeUpgrade(RepositoryCache.java:469)
at org.modeshape.jcr.JcrRepository$RunningState.completeInitialization(JcrRepository.java:1331)
at org.modeshape.jcr.JcrRepository.doStart(JcrRepository.java:390)
at org.modeshape.jcr.JcrRepository.start(JcrRepository.java:312)
at org.modeshape.jcr.JcrRepository.completeRestore(JcrRepository.java:543)
at org.modeshape.jcr.BackupService.restoreRepository(BackupService.java:161)
at org.modeshape.jcr.JcrRepositoryManager.restoreRepository(JcrRepositoryManager.java:87)
at org.modeshape.jcr.JcrRepositoryManager.restoreRepository(JcrRepositoryManager.java:81)
at org.apache.jsp.console.tools.repository.restore_jsp.restore(restore_jsp.java:93)
...
Couple of questions:
1. Is there a way we can monitorize the restore progress to see if it's blocked, it's working and what is the progress? Maybe changing modeshape to DEBUG mode in the logs?
2. What could the problem? Attached you can find Infinispan and modeshape config files.
3. Am I missing something?
Thanks in advance.
Additional info:
Running in DEBUG mode I can see the following lines:
INFO: Running ModeShape 4.0.0.Alpha1 upgrade function...
FINE: There is no explicit cache named 'empower.repository/default' defined in the workspace cache container, using a default cache
FINE: The 'empower.repository/default' workspace cache is using the cache configuration: 'Configuration{clustering=ClusteringConfiguration [asyncConfiguration=AsyncConfiguration [attributes=[asyncMarshalling=false, replicationQueue=null, replicationQueueMaxElements=1000, replicationQueueInterval=10, useReplicationQueue=false]], hashConfiguration=HashConfiguration [attributes=[consistentHashFactory=null, numOwners=2, capacityFactor=1.0, numSegments=60, hash=MurmurHash3]], l1Configuration=L1Configuration [attributes=[enabled=false, invalidationThreshold=0, lifespan=600000, cleanupTaskFrequency=60000]], stateTransferConfiguration=StateTransferConfiguration[fetchInMemoryState=true, timeout=240000, awaitInitialTransfer=true, chunkSize=512], syncConfiguration=SyncConfiguration [attributes=[replTimeout=15000]], partitionHandlingConfiguration=PartitionHandlingConfiguration [attributes=[enabled=false]], attributes=[cacheMode=LOCAL]], customInterceptors=CustomInterceptorsConfiguration [interceptors=[]], dataContainer=DataContainerConfiguration [attributes=[dataContainer=null, keyEquivalence=org.infinispan.commons.equivalence.AnyEquivalence@b64e155, valueEquivalence=org.infinispan.commons.equivalence.AnyEquivalence@b64e155, properties={}]], deadlockDetection=DeadlockDetectionConfiguration [attributes=[enabled=false, spinDuration=100]], eviction=EvictionConfiguration [attributes=[threadPolicy=DEFAULT, strategy=LRU, maxEntries=50000]], expiration=ExpirationConfiguration [attributes=[wakeUpInterval=60000, reaperEnabled=true, maxIdle=6000, lifespan=120000]], indexing=IndexingConfiguration [attributes=[index=NONE, autoConfig=false, properties={}]], invocationBatching=InvocationBatchingConfiguration [attributes=[enabled=false]], jmxStatistics=JMXStatisticsConfiguration [attributes=[enabled=false]], persistence=PersistenceConfiguration [attributes=[passivation=false], stores=[]], locking=LockingConfiguration [attributes=[isolationLevel=READ_COMMITTED, useLockStriping=false, lockAcquisitionTimeout=10000, concurrencyLevel=32, writeSkewCheck=false]], modules={}, security=SecurityConfiguration [authorization=AuthorizationConfiguration [attributes=[enabled=false, roles=[]]]], storeAsBinary=StoreAsBinaryConfiguration [attributes=[enabled=false, storeKeysAsBinary=true, storeValuesAsBinary=true]], transaction=TransactionConfiguration [attributes=[transactionManagerLookup=org.infinispan.transaction.lookup.GenericTransactionManagerLookup@c05994b, transactionSynchronizationRegistryLookup=null, syncRollbackPhase=true, syncCommitPhase=true, cacheStopTimeout=30000, transactionProtocol=DEFAULT, completedTxTimeout=60000, transactionMode=NON_TRANSACTIONAL, reaperWakeUpInterval=30000, lockingMode=OPTIMISTIC, autoCommit=true, useSynchronization=false, useEagerLocking=false, eagerLockingSingleNode=false, use1PcForAutoCommitTransactions=false], recovery=RecoveryConfiguration [attributes=[enabled=false, recoveryInfoCacheName=__recoveryInfoCacheName__]]], versioning=[scheme=NONE, enabled=false], unsafe=[unrealiableReturnValues=false], sites=SitesConfiguration [backupFor=BackupForConfiguration [attributes=[remoteCache=null, remoteSite=null]], allBackups=[], attributes=[disableBackups=false, inUseBackupSites=[]]], compatibility=CompatibilityModeConfiguration [attributes=[enabled=false, marshaller=null]]}'
FINE: Queries with indexes are enabled for the 'empower.repository' repository. Executing queries may require scanning the repository contents when the query cannot use the defined indexes.
Then nothing else...
-
Config files.zip 2.3 KB