[JBoss JIRA] (ISPN-2751) NPE after JBossMarshaller stops
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-2751?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-2751:
----------------------------------------
In the past we had issues where the RPC dispatcher was stopping *after* the cache manager had stopped. This lead to NPEs in ExternalizerTable (ISPN-2025) as a result of trying to deserialize stuff after the cache managed had stopped. At the time we added a workaround to handle null commands, which effectively are the result of externalizer table not being able to deserialize objects (normally due to the sequence of events mentioned) and we reverted it (ISPN-2063) once AS7-3180 had been implemented.
The problem now does not appear to be that we cannot deserialize something, but rather than while sending a response to *something*, the cache manager was stopped leading to a null externalizer table. The circumstances look very similar to ISPN-2752 actually and the result seems to be circumstantial:
* In ISPN-2752 we see that the cache manager has started stopping but the externalizer table is still there, because the response is being marshalled.
* In this JIRA, we see that the cache manager has fully stopped, the externalizer table is not there any more, but the JGroups transport (or RPC dispatcher) is still actively trying to send a reply to a command.
Some TRACE logs, including not only org.jgroups and org.infinispan, but also org.jboss.as.clustering would be very handy to try to better understand how to fix this.
> NPE after JBossMarshaller stops
> -------------------------------
>
> Key: ISPN-2751
> URL: https://issues.jboss.org/browse/ISPN-2751
> Project: Infinispan
> Issue Type: Bug
> Components: Marshalling
> Affects Versions: 5.2.0.CR2
> Reporter: Michal Linhard
> Assignee: Galder Zamarreño
> Priority: Minor
> Fix For: 5.2.0.Final
>
> Attachments: serverlogs.zip
>
>
> JBossMarshaller is used by JGroups even after it's stopped
> which produces NPE on nonexistent externalizerTable:
> https://github.com/infinispan/infinispan/blob/master/core/src/main/java/o...
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years, 11 months
[JBoss JIRA] (ISPN-2752) IllegalStateException on shutdown
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-2752?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-2752:
----------------------------------------
IRC discussion: https://gist.github.com/647ec76c9e3d7cc28ef3
> IllegalStateException on shutdown
> ---------------------------------
>
> Key: ISPN-2752
> URL: https://issues.jboss.org/browse/ISPN-2752
> Project: Infinispan
> Issue Type: Bug
> Affects Versions: 5.2.0.CR2
> Reporter: Michal Linhard
> Assignee: Dan Berindei
> Priority: Minor
> Fix For: 5.2.0.Final
>
>
> This happens on graceful shutdown of 8 or 6 nodes of 5.2.0.CR2:
> {code}
> 07:17:45,892 ERROR [org.infinispan.topology.ClusterTopologyManagerImpl] ISPN000196: Failed to recover cluster state after the current node became the coordinator: java.util.concurrent.ExecutionException: org.infinispan.CacheException: Remote (node0005/default) failed unexpectedly
> at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:232) [rt.jar:1.6.0_33]
> at java.util.concurrent.FutureTask.get(FutureTask.java:91) [rt.jar:1.6.0_33]
> at org.infinispan.topology.ClusterTopologyManagerImpl.executeOnClusterSync(ClusterTopologyManagerImpl.java:567) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.topology.ClusterTopologyManagerImpl.recoverClusterStatus(ClusterTopologyManagerImpl.java:432) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.topology.ClusterTopologyManagerImpl.handleNewView(ClusterTopologyManagerImpl.java:231) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.handleViewChange(ClusterTopologyManagerImpl.java:597) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_33]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_33]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_33]
> at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_33]
> at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:212) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_33]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_33]
> at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_33]
> Caused by: org.infinispan.CacheException: Remote (node0005/default) failed unexpectedly
> at org.infinispan.remoting.transport.AbstractTransport.parseResponseAndAddToResponseList(AbstractTransport.java:96) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:541) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.topology.ClusterTopologyManagerImpl$2.call(ClusterTopologyManagerImpl.java:549) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.topology.ClusterTopologyManagerImpl$2.call(ClusterTopologyManagerImpl.java:546) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_33]
> at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_33]
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_33]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_33]
> at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_33]
> at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.0.0.GA-redhat-2.jar:2.0.0.GA-redhat-2]
> Caused by: java.lang.IllegalStateException: transport was closed
> at org.jgroups.blocks.GroupRequest.transportClosed(GroupRequest.java:273) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.jgroups.blocks.RequestCorrelator.stop(RequestCorrelator.java:269) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.jgroups.blocks.MessageDispatcher.stop(MessageDispatcher.java:152) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.jgroups.blocks.MessageDispatcher.channelDisconnected(MessageDispatcher.java:455) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.jgroups.Channel.notifyChannelDisconnected(Channel.java:507) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.jgroups.JChannel.disconnect(JChannel.java:363) [jgroups-3.2.6.Final-redhat-1.jar:3.2.6.Final-redhat-1]
> at org.infinispan.remoting.transport.jgroups.JGroupsTransport.stop(JGroupsTransport.java:258) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_33]
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_33]
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_33]
> at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_33]
> at org.infinispan.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:203) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:883) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.factories.AbstractComponentRegistry.internalStop(AbstractComponentRegistry.java:690) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.factories.AbstractComponentRegistry.stop(AbstractComponentRegistry.java:568) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.factories.GlobalComponentRegistry.stop(GlobalComponentRegistry.java:260) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.manager.DefaultCacheManager.stop(DefaultCacheManager.java:742) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.infinispan.manager.AbstractDelegatingEmbeddedCacheManager.stop(AbstractDelegatingEmbeddedCacheManager.java:179) [infinispan-core-5.2.0.CR2-redhat-1.jar:5.2.0.CR2-redhat-1]
> at org.jboss.as.clustering.infinispan.subsystem.EmbeddedCacheManagerService.stop(EmbeddedCacheManagerService.java:76) [jboss-datagrid-infinispan-6.1.0.ER9-redhat-1.jar:6.1.0.ER9-redhat-1]
> at org.jboss.msc.service.ServiceControllerImpl$StopTask.stopService(ServiceControllerImpl.java:1911) [jboss-msc-1.0.2.GA-redhat-2.jar:1.0.2.GA-redhat-2]
> at org.jboss.msc.service.ServiceControllerImpl$StopTask.run(ServiceControllerImpl.java:1874) [jboss-msc-1.0.2.GA-redhat-2.jar:1.0.2.GA-redhat-2]
> at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_33]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_33]
> at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_33]
> {code}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years, 11 months
[JBoss JIRA] (ISPN-2697) HotRodServer startup fails when its record cannot be inserted into topology cache
by Bela Ban (JIRA)
[ https://issues.jboss.org/browse/ISPN-2697?page=com.atlassian.jira.plugin.... ]
Bela Ban commented on ISPN-2697:
--------------------------------
Why do the state transfer commands not have flags ? I fail to see why a command cannot carry an additional flag, as you already have around 20 ! Do you consider those flags hacks, too ?
Or are you saying that *HotRod* cannot ship flags from a client to a server ? Then your argument would actually make sense...
> HotRodServer startup fails when its record cannot be inserted into topology cache
> ---------------------------------------------------------------------------------
>
> Key: ISPN-2697
> URL: https://issues.jboss.org/browse/ISPN-2697
> Project: Infinispan
> Issue Type: Bug
> Components: Remote protocols
> Affects Versions: 5.2.0.Beta6
> Reporter: Radim Vansa
> Assignee: Galder Zamarreño
> Priority: Critical
> Fix For: 5.2.0.Final
>
>
> When the HotRodServer starts it inserts its record to __hotRodTopologyCache ({{HotRodServer.addSelfToTopologyView(...)}}).
> However, this put may very easily fail - as the command is broadcasted using NAKACK2 protocol, if the message gets lost and there's no following broadcasted message, the message will be not retransmitted and the put operation times out (Replication timeout), which fails the whole HotRodServer startup, all because of one lost UDP message.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years, 11 months
[JBoss JIRA] (ISPN-2751) NPE after JBossMarshaller stops
by Michal Linhard (JIRA)
[ https://issues.jboss.org/browse/ISPN-2751?page=com.atlassian.jira.plugin.... ]
Michal Linhard updated ISPN-2751:
---------------------------------
Attachment: serverlogs.zip
serverlogs.zip trace logs from run of 6 nodes on my laptop. the NPE occured 3 times:
{code}
node05.log 872902 12:15:03,782 ERROR [org.jgroups.blocks.RequestCorrelator] failed marshalling rsp (SuccessfulResponse{responseValue={}} ): java.lang.NullPointerException
node06.log 892500 12:15:03,865 ERROR [org.jgroups.blocks.RequestCorrelator] failed marshalling rsp (SuccessfulResponse{responseValue={}} ): java.lang.NullPointerException
node03.log 1080114 12:15:04,639 ERROR [org.jgroups.blocks.RequestCorrelator] failed marshalling rsp (SuccessfulResponse{responseValue={}} ): java.lang.NullPointerException
{code}
there were also some other issues during the run, but hopefully this run illustrates what you need.
> NPE after JBossMarshaller stops
> -------------------------------
>
> Key: ISPN-2751
> URL: https://issues.jboss.org/browse/ISPN-2751
> Project: Infinispan
> Issue Type: Bug
> Components: Marshalling
> Affects Versions: 5.2.0.CR2
> Reporter: Michal Linhard
> Assignee: Galder Zamarreño
> Priority: Minor
> Fix For: 5.2.0.Final
>
> Attachments: serverlogs.zip
>
>
> JBossMarshaller is used by JGroups even after it's stopped
> which produces NPE on nonexistent externalizerTable:
> https://github.com/infinispan/infinispan/blob/master/core/src/main/java/o...
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years, 11 months
[JBoss JIRA] (ISPN-2770) Wrong format arguments in trace log message
by Michal Linhard (JIRA)
Michal Linhard created ISPN-2770:
------------------------------------
Summary: Wrong format arguments in trace log message
Key: ISPN-2770
URL: https://issues.jboss.org/browse/ISPN-2770
Project: Infinispan
Issue Type: Bug
Affects Versions: 5.2.0.CR2
Reporter: Michal Linhard
Assignee: Mircea Markus
https://github.com/infinispan/infinispan/blob/master/core/src/main/java/o...
{code}
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) java.util.logging.ErrorManager: 5: Formatting error
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) java.util.MissingFormatArgumentException: Format specifier 's'
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at java.util.Formatter.format(Formatter.java:2432)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at java.util.Formatter.format(Formatter.java:2367)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at java.lang.String.format(String.java:2769)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.ExtLogRecord.formatRecord(ExtLogRecord.java:434)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.ExtLogRecord.getFormattedMessage(ExtLogRecord.java:397)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.formatters.Formatters$10.renderRaw(Formatters.java:358)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.formatters.Formatters$JustifyingFormatStep.render(Formatters.java:150)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.formatters.MultistepFormatter.format(MultistepFormatter.java:86)
node05: 11:57:22,950 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.ExtFormatter.format(ExtFormatter.java:35)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:49)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:290)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:298)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:298)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:298)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:298)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.Logger.logRaw(Logger.java:721)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logmanager.Logger.log(Logger.java:672)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logging.JBossLogManagerLogger.doLogf(JBossLogManagerLogger.java:50)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logging.Logger.logf(Logger.java:2126)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.jboss.logging.DelegatingBasicLogger.tracef(DelegatingBasicLogger.java:134)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.infinispan.topology.ClusterCacheStatus.addMember(ClusterCacheStatus.java:106)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.infinispan.topology.ClusterTopologyManagerImpl.recoverClusterStatus(ClusterTopologyManagerImpl.java:460)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.infinispan.topology.ClusterTopologyManagerImpl.handleNewView(ClusterTopologyManagerImpl.java:231)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.handleViewChange(ClusterTopologyManagerImpl.java:597)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
node05: 11:57:22,951 ERROR [stderr] (notification-thread-0) at java.lang.reflect.Method.invoke(Method.java:597)
node05: 11:57:22,952 ERROR [stderr] (notification-thread-0) at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:212)
node05: 11:57:22,952 ERROR [stderr] (notification-thread-0) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
node05: 11:57:22,952 ERROR [stderr] (notification-thread-0) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
node05: 11:57:22,952 ERROR [stderr] (notification-thread-0) at java.lang.Thread.run(Thread.java:662)
{code}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
11 years, 11 months