[infinispan-issues] [JBoss JIRA] (ISPN-7488) Node tries to register component after stopping

Mon Feb 20 05:26:00 EST 2017

    [ https://issues.jboss.org/browse/ISPN-7488?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13365985#comment-13365985 ] 

Sebastian Łaskawiec commented on ISPN-7488:
-------------------------------------------

I think the node tries to process data when it's almost stopped. This may lead to even more scary logs:
{noformat}
[transactions-repository-1-kf1g8] 10:18:32,132 INFO  [org.jboss.as.clustering.infinispan] (MSC service thread 1-7) DGISPN0002: Stopped transactions cache from clustered container
[transactions-repository-1-kf1g8] 10:18:32,072 ERROR [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-7-5) ISPN005022: Exception writing response with messageId=1044: org.infinispan.commons.CacheConfigurationException: Unable to configure component (type: class org.infinispan.compat.ConverterEntryMapper, instance org.infinispan.compat.ConverterEntryMapper at 58c1e8a6)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.wireDependencies(AbstractComponentRegistry.java:152)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.local.LocalCacheStream.map(LocalCacheStream.java:130)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.local.LocalCacheStream.map(LocalCacheStream.java:66)
[transactions-repository-1-kf1g8] at org.infinispan.cache.impl.TypeConverterDelegatingAdvancedCache$TypeConverterEntrySet.stream(TypeConverterDelegatingAdvancedCache.java:477)
[transactions-repository-1-kf1g8] at org.infinispan.interceptors.distribution.DistributionBulkInterceptor$BackingKeySet.lambda$stream$0(DistributionBulkInterceptor.java:300)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.AbstractCacheStream.lambda$supplierForSegments$3(AbstractCacheStream.java:619)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.termop.object.MapIteratorOperation.performOperationRehashAware(MapIteratorOperation.java:55)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.DistributedCacheStream.performLocalRehashAwareOperation(DistributedCacheStream.java:741)
[transactions-repository-1-kf1g8] at org.infinispan.stream.impl.DistributedCacheStream.lambda$rehashAwareIteration$13(DistributedCacheStream.java:688)
[transactions-repository-1-kf1g8] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[transactions-repository-1-kf1g8] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[transactions-repository-1-kf1g8] at java.lang.Thread.run(Thread.java:745)
[transactions-repository-1-kf1g8] Caused by: org.infinispan.IllegalLifecycleStateException: Trying to register a component after stopping: org.infinispan.factories.EntryMetaFactory
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.registerComponentInternal(AbstractComponentRegistry.java:185)
[transactions-repository-1-kf1g8] at org.infinispan.factories.ComponentRegistry.registerComponentInternal(ComponentRegistry.java:186)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.registerComponent(AbstractComponentRegistry.java:172)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.registerComponent(AbstractComponentRegistry.java:168)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.createComponentFactoryInternal(AbstractComponentRegistry.java:349)
[transactions-repository-1-kf1g8] at org.infinispan.factories.ComponentRegistry.createComponentFactoryInternal(ComponentRegistry.java:195)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.getFactory(AbstractComponentRegistry.java:328)
[transactions-repository-1-kf1g8] at org.infinispan.factories.ComponentRegistry.getFactory(ComponentRegistry.java:176)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.getOrCreateComponent(AbstractComponentRegistry.java:294)
[transactions-repository-1-kf1g8] at org.infinispan.factories.ComponentRegistry.getOrCreateComponent(ComponentRegistry.java:155)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.invokeInjectionMethod(AbstractComponentRegistry.java:247)
[transactions-repository-1-kf1g8] at org.infinispan.factories.AbstractComponentRegistry.wireDependencies(AbstractComponentRegistry.java:148)
[transactions-repository-1-kf1g8] ... 11 more
[transactions-repository-1-kf1g8] 

[transactions-repository-1-kf1g8] 10:18:33,059 INFO  [org.infinispan.globalstate.impl.GlobalStateManagerImpl] (MSC service thread 1-1) ISPN000390: Persisted state, version=9.0.0-SNAPSHOT timestamp=2017-02-20T10:18:33.058Z
[transactions-repository-1-kf1g8] 10:18:33,104 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-1) ISPN000080: Disconnecting JGroups channel clustered
[transactions-repository-1-kf1g8] 10:18:33,130 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-1) ISPN000082: Stopping the RpcDispatcher for channel clustered
[transactions-repository-1-kf1g8] 10:18:33,139 ERROR [org.infinispan.CLUSTER] (transport-thread--p4-t16) ISPN000196: Failed to recover cluster state after the current node became the coordinator (or after merge): org.infinispan.commons.CacheException: java.lang.IllegalStateException: channel is not connected
[transactions-repository-1-kf1g8] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.rethrowAsCacheException(CommandAwareRpcDispatcher.java:134)
[transactions-repository-1-kf1g8] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:117)
[transactions-repository-1-kf1g8] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotelyAsync(JGroupsTransport.java:589)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl.executeOnClusterSync(ClusterTopologyManagerImpl.java:578)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl.recoverClusterStatus(ClusterTopologyManagerImpl.java:453)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl.becomeCoordinator(ClusterTopologyManagerImpl.java:352)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl.handleClusterView(ClusterTopologyManagerImpl.java:331)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl.access$500(ClusterTopologyManagerImpl.java:76)
[transactions-repository-1-kf1g8] at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.lambda$handleViewChange$0(ClusterTopologyManagerImpl.java:729)
[transactions-repository-1-kf1g8] at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144)
[transactions-repository-1-kf1g8] at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33)
[transactions-repository-1-kf1g8] at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174)
[transactions-repository-1-kf1g8] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[transactions-repository-1-kf1g8] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[transactions-repository-1-kf1g8] at java.lang.Thread.run(Thread.java:745)
[transactions-repository-1-kf1g8] Caused by: java.lang.IllegalStateException: channel is not connected
[transactions-repository-1-kf1g8] at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.down(MessageDispatcher.java:598)
[transactions-repository-1-kf1g8] at org.jgroups.blocks.RequestCorrelator.sendRequest(RequestCorrelator.java:170)
[transactions-repository-1-kf1g8] at org.jgroups.blocks.GroupRequest.sendRequest(GroupRequest.java:287)
[transactions-repository-1-kf1g8] at org.jgroups.blocks.GroupRequest.sendRequest(GroupRequest.java:76)
[transactions-repository-1-kf1g8] at org.jgroups.blocks.Request.execute(Request.java:48)
[transactions-repository-1-kf1g8] at org.jgroups.blocks.MessageDispatcher.cast(MessageDispatcher.java:319)
[transactions-repository-1-kf1g8] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processCalls(CommandAwareRpcDispatcher.java:385)
[transactions-repository-1-kf1g8] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:113)
[transactions-repository-1-kf1g8] ... 13 more
[transactions-repository-1-kf1g8] 
[transactions-repository-1-kf1g8] 10:18:33,162 FATAL [org.infinispan.CLUSTER] (transport-thread--p4-t16) ISPN100004: After merge (or coordinator change), the coordinator failed to recover cluster. Cluster members are [transactions-repository-1-kf1g8, transactions-repository-2-639jf, transactions-repository-2-6ltt6].

[transactions-repository-1-kf1g8] 10:18:33,897 INFO  [org.jboss.as] (MSC service thread 1-8) WFLYSRV0050: Infinispan Server 9.0.0-SNAPSHOT (WildFly Core 2.2.0.Final) stopped in 3509ms
[transactions-repository-1-kf1g8] *** JBossAS process (81) received TERM signal ***
{noformat}

> Node tries to register component after stopping
> -----------------------------------------------
>
>                 Key: ISPN-7488
>                 URL: https://issues.jboss.org/browse/ISPN-7488
>             Project: Infinispan
>          Issue Type: Sub-task
>          Components: Cloud Integrations, Core
>    Affects Versions: 9.0.0.CR1
>         Environment: * OpenShift {{v1.5.0-alpha.2+e4b43ee}}
> * Custom Infinispan Server build (based on [these instructions|https://github.com/slaskawi/infinispan-1/tree/custom_image]). SHA1 {{2b0731b21649a88a75ed71d21b9cc06ba365e947}}
>            Reporter: Sebastian Łaskawiec
>
> When I was performing [Spring Session and Kubernetes Rolling Update demo|https://bluejeans.com/s/pYKUg/] I encountered a couple of problems.
> One of the is this:
> {noformat}
> [transactions-repository-1-4z05w] 18:09:06,122 WARN  [org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler] (remote-thread--p2-t5) ISPN000071: Caught exception when handling command CacheTopologyControlCommand{cache=___script_cache, type=REBALANCE_CONFIRM, sender=transactions-repository-1-1f8dx, joinInfo=null, topologyId=9, rebalanceId=0, currentCH=null, pendingCH=null, availabilityMode=null, actualMembers=null, throwable=null, viewId=4}: org.infinispan.commons.CacheConfigurationException: Unable to configure component (type: class org.infinispan.topology.CacheTopologyControlCommand, instance CacheTopologyControlCommand{cache=___script_cache, type=REBALANCE_CONFIRM, sender=transactions-repository-1-1f8dx, joinInfo=null, topologyId=9, rebalanceId=0, currentCH=null, pendingCH=null, availabilityMode=null, actualMembers=null, throwable=null, viewId=4})
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.wireDependencies(AbstractComponentRegistry.java:152)
> [transactions-repository-1-4z05w] at org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler$2.run(GlobalInboundInvocationHandler.java:160)
> [transactions-repository-1-4z05w] at org.infinispan.util.concurrent.BlockingTaskAwareExecutorServiceImpl$RunnableWrapper.run(BlockingTaskAwareExecutorServiceImpl.java:203)
> [transactions-repository-1-4z05w] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [transactions-repository-1-4z05w] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [transactions-repository-1-4z05w] at java.lang.Thread.run(Thread.java:745)
> [transactions-repository-1-4z05w] Caused by: org.infinispan.IllegalLifecycleStateException: Trying to register a component after stopping: org.infinispan.topology.LocalTopologyManagerFactory
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.registerComponentInternal(AbstractComponentRegistry.java:185)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.registerComponent(AbstractComponentRegistry.java:172)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.registerComponent(AbstractComponentRegistry.java:168)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.createComponentFactoryInternal(AbstractComponentRegistry.java:349)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.getFactory(AbstractComponentRegistry.java:328)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.getOrCreateComponent(AbstractComponentRegistry.java:294)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.invokeInjectionMethod(AbstractComponentRegistry.java:247)
> [transactions-repository-1-4z05w] at org.infinispan.factories.AbstractComponentRegistry.wireDependencies(AbstractComponentRegistry.java:148)
> [transactions-repository-1-4z05w] ... 5 more
> {noformat}
> Full logs from Rolling Update process might be found here: https://gist.github.com/slaskawi/530241bb695f1f490bcb25eabaf9d676
> Steps to reproduce:
> * Start local OpenShift Cluster
> * invoke `./init_infrastructure.sh` from https://github.com/slaskawi/presentations/tree/ISPN-7487-reproducer
> * invoke `cd transaction-creator && mvn fabric8:run`
> * Do the rolling update: `oc deploy transactions-repository --latest -n myproject`
> * Observe logs `kubetail -l environment=infrastructure`

--
This message was sent by Atlassian JIRA
(v7.2.3#72005)