Bug 900497 (JBPAPP6-1471)
| Summary: | Sporadic NPE in org.jgroups.protocols.RSVP.up during deployment | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | [JBoss] JBoss Enterprise Application Platform 6 | Reporter: | Marek Schmidt <maschmid> | ||||||
| Component: | Clustering | Assignee: | Marek Schmidt <maschmid> | ||||||
| Status: | CLOSED WORKSFORME | QA Contact: | |||||||
| Severity: | high | Docs Contact: | |||||||
| Priority: | high | ||||||||
| Version: | 6.0.0 | CC: | bela, maschmid, rhusar | ||||||
| Target Milestone: | --- | ||||||||
| Target Release: | --- | ||||||||
| Hardware: | Unspecified | ||||||||
| OS: | Unspecified | ||||||||
| URL: | http://jira.jboss.org/jira/browse/JBPAPP6-1471 | ||||||||
| Whiteboard: | |||||||||
| Fixed In Version: | Doc Type: | Bug Fix | |||||||
| Doc Text: | Story Points: | --- | |||||||
| Clone Of: | Environment: |
RHEL5 x86, JRE 1.6.0 IBM J9 2.4 Linux x86-32
|
|||||||
| Last Closed: | 2012-12-07 11:30:42 UTC | Type: | Bug | ||||||
| Regression: | --- | Mount Type: | --- | ||||||
| Documentation: | --- | CRM: | |||||||
| Verified Versions: | Category: | --- | |||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||
| Embargoed: | |||||||||
| Attachments: |
|
||||||||
Attachment: Added: server1.log Attachment: Added: server2.log Marek, is CR1 affected as well? Can you update the broken link? I am wondering why I have never seen this. Updated, It has only occurred once on EAP 6.0.0 ER 8 out of several runs, and I have not seen it since, so I don't know. This is strange; the NPE in RSVP happens because (in JChannel.connect()) we send up an event to fetch the JChannel's address from the transport (UDP) and RSVP has a null ref to the ProtocolStack. The top protocol (RSVP) forwards all events from below to the ProtocolStack, and the ref to the stack is set at creation time, *before* JChannel.connect() is called. Paul, do you insert RSVP dynamically ? Docs QE Status: Removed: NEW Never seen since. |
project_key: JBPAPP6 The following NPE occurred once during one of the node startup in a two-node cluster failover test. The test restarts the nodes several times. from the server1.log (where node1 is stopped to failover to node2 and then started again, where the deployment fails with NPE): (also note the {noformat} 10:28:04,118 SEVERE [org.jgroups.protocols.UNICAST2] (OOB-17,null) node1/web: sender window for node1/web not found {noformat} line during the shutdown) {noformat} 10:27:38,548 INFO [org.jboss.as.server] (management-handler-thread - 2) JBAS018559: Deployed "weld-clustering-tests.war" 10:27:54,772 INFO [org.jboss.as.clustering] (Incoming-1,null) JBAS010225: New cluster view for partition web (id: 1, delta: 1, merge: false) : [node1/web, node2/web] 10:27:54,774 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,null) ISPN000094: Received new cluster view: [node1/web|1] [node1/web, node2/web] 10:27:54,784 INFO [org.jboss.as.clustering] (Incoming-3,null) JBAS010225: New cluster view for partition ejb (id: 1, delta: 1, merge: false) : [node1/ejb, node2/ejb] 10:27:54,785 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-3,null) ISPN000094: Received new cluster view: [node1/ejb|1] [node1/ejb, node2/ejb] 10:28:03,628 INFO [org.jboss.as.osgi] (MSC service thread 1-2) JBAS011908: Unregister module: Module "deployment.weld-clustering-tests.war:main" from Service Module Loader 10:28:03,648 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-2) ISPN000029: Passivating all entries to disk 10:28:03,650 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-5) ISPN000029: Passivating all entries to disk 10:28:03,651 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-5) ISPN000030: Passivated 0 entries in 0 milliseconds 10:28:03,658 INFO [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016009: Stopping weld service for deployment weld-clustering-tests.war 10:28:03,663 INFO [org.jboss.as.clustering.infinispan] (MSC service thread 1-5) JBAS010282: Stopped default-host/weld-clustering-tests cache from web container 10:28:03,696 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-2) ISPN000030: Passivated 1 entries in 48 milliseconds 10:28:03,714 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-5) ISPN000029: Passivating all entries to disk 10:28:03,715 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-5) ISPN000030: Passivated 0 entries in 1 milliseconds 10:28:03,724 INFO [org.jboss.as.clustering.infinispan] (MSC service thread 1-2) JBAS010282: Stopped org.jboss.weld.tests.clustering.numberguess.decorator.EjbGameBean cache from ejb container 10:28:03,729 INFO [org.jboss.as.clustering.infinispan] (MSC service thread 1-5) JBAS010282: Stopped repl cache from ejb container 10:28:03,772 INFO [org.jboss.as.clustering.infinispan] (MSC service thread 1-4) JBAS010282: Stopped remote-connector-client-mappings cache from ejb container 10:28:04,043 INFO [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015877: Stopped deployment weld-clustering-tests.war in 424ms 10:28:04,047 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-3) ISPN000029: Passivating all entries to disk 10:28:04,048 INFO [org.infinispan.eviction.PassivationManagerImpl] (MSC service thread 1-3) ISPN000030: Passivated 0 entries in 1 milliseconds 10:28:04,057 INFO [org.jboss.as.clustering.infinispan] (MSC service thread 1-3) JBAS010282: Stopped repl cache from web container 10:28:04,104 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-5) ISPN000082: Stopping the RpcDispatcher 10:28:04,118 SEVERE [org.jgroups.protocols.UNICAST2] (OOB-17,null) node1/web: sender window for node1/web not found 10:28:04,135 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-4) ISPN000082: Stopping the RpcDispatcher 10:28:04,506 INFO [org.jboss.as.repository] (management-handler-thread - 3) JBAS014901: Content removed from location /mnt/hudson_workspace/workspace/Weld-ftest-cluster-EAP6-matrix/LABEL/selenium-ff3-rhel5-x86/jdk/ibm16/node1/jboss-eap-6.0/standalone/data/content/3f/5b2d53a3ce0d864770e0b8fda059a4b9f537e6/content 10:28:04,507 INFO [org.jboss.as.server] (management-handler-thread - 3) JBAS018558: Undeployed "weld-clustering-tests.war" 10:28:04,641 INFO [org.apache.catalina.core.StandardContext] (MSC service thread 1-1) Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started 10:28:14,621 INFO [org.jboss.as.configadmin] (ServerService Thread Pool -- 28) JBAS016200: Activating ConfigAdmin Subsystem 10:28:14,663 INFO [org.jboss.as.osgi] (ServerService Thread Pool -- 43) JBAS011906: Activating OSGi Subsystem 10:28:14,667 INFO [org.jboss.as.security] (ServerService Thread Pool -- 48) JBAS013101: Activating Security Subsystem 10:28:14,689 INFO [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 33) JBAS010280: Activating Infinispan subsystem. 10:28:14,710 INFO [org.jboss.as.webservices] (ServerService Thread Pool -- 52) JBAS015537: Activating WebServices Extension 10:28:14,711 INFO [org.jboss.as.naming] (ServerService Thread Pool -- 42) JBAS011800: Activating Naming Subsystem 10:28:14,723 INFO [org.jboss.as.clustering.jgroups] (ServerService Thread Pool -- 37) JBAS010260: Activating JGroups subsystem. 10:28:14,886 INFO [org.jboss.as.security] (MSC service thread 1-1) JBAS013100: Current PicketBox version=4.0.9.Final-redhat-1 10:28:14,945 INFO [org.jboss.as.connector.logging] (MSC service thread 1-4) JBAS010408: Starting JCA Subsystem (JBoss IronJacamar 1.0.11.Final-redhat-1) 10:28:15,279 INFO [org.jboss.as.connector.subsystems.datasources] (ServerService Thread Pool -- 29) JBAS010403: Deploying JDBC-compliant driver class org.h2.Driver (version 1.3) 10:28:15,429 INFO [org.jboss.as.naming] (MSC service thread 1-1) JBAS011802: Starting Naming Service 10:28:15,472 INFO [org.jboss.as.mail.extension] (MSC service thread 1-4) JBAS015400: Bound mail session [java:jboss/mail/Default] 10:28:15,610 INFO [org.jboss.ws.common.management.AbstractServerConfig] (MSC service thread 1-5) JBoss Web Services - Stack CXF Server 4.0.4.GA-redhat-1 10:28:16,209 INFO [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-6) Starting Coyote HTTP/1.1 on http-/10.16.95.23:8080 10:28:16,214 INFO [org.apache.coyote.ajp.AjpProtocol] (MSC service thread 1-2) Starting Coyote AJP/1.3 on ajp-/10.16.95.23:8009 10:28:16,385 INFO [org.jboss.modcluster.ModClusterService] (ModClusterService lifecycle - 1) Initializing mod_cluster 1.2.1.Final-redhat-1 10:28:16,678 INFO [org.jboss.modcluster.advertise.impl.AdvertiseListenerImpl] (ModClusterService lifecycle - 1) Listening to proxy advertisements on 224.0.1.105:23,364 10:28:16,710 INFO [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 33) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be pasivated. 10:28:16,721 INFO [org.infinispan.configuration.cache.EvictionConfigurationBuilder] (ServerService Thread Pool -- 33) ISPN000152: Passivation configured without an eviction policy being selected. Only manually evicted entities will be pasivated. 10:28:16,965 INFO [org.jboss.as.remoting] (MSC service thread 1-2) JBAS017100: Listening on 10.16.95.23:9999 10:28:16,965 INFO [org.jboss.as.remoting] (MSC service thread 1-1) JBAS017100: Listening on 10.16.95.23:4447 10:28:16,974 INFO [org.jboss.as.server.deployment.scanner] (MSC service thread 1-5) JBAS015012: Started FileSystemDeploymentService for directory /mnt/hudson_workspace/workspace/Weld-ftest-cluster-EAP6-matrix/LABEL/selenium-ff3-rhel5-x86/jdk/ibm16/node1/jboss-eap-6.0/standalone/deployments 10:28:16,999 INFO [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010400: Bound data source [java:jboss/datasources/ExampleDS] 10:28:17,184 INFO [org.jboss.as] (Controller Boot Thread) JBAS015951: Admin console listening on http://10.16.95.23:9990 10:28:17,186 INFO [org.jboss.as] (Controller Boot Thread) JBAS015874: JBoss EAP 6.0.0.GA (AS 7.1.2.Final-redhat-1) started in 8631ms - Started 136 of 276 services (139 services are passive or on-demand) 10:28:19,608 INFO [org.jboss.as.repository] (management-handler-thread - 2) JBAS014900: Content added at location /mnt/hudson_workspace/workspace/Weld-ftest-cluster-EAP6-matrix/LABEL/selenium-ff3-rhel5-x86/jdk/ibm16/node1/jboss-eap-6.0/standalone/data/content/30/b66f3e1520adb31ebba0bcb5b562bb43009e47/content 10:28:19,628 INFO [org.jboss.as.server.deployment] (MSC service thread 1-1) JBAS015876: Starting deployment of "weld-clustering-tests.war" 10:28:20,357 INFO [org.jboss.weld.deployer] (MSC service thread 1-2) JBAS016002: Processing weld deployment weld-clustering-tests.war 10:28:20,374 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named RandomStatelessEjb in deployment unit deployment "weld-clustering-tests.war" are as follows: java:global/weld-clustering-tests/RandomStatelessEjb!org.jboss.weld.tests.clustering.numberguess.decorator.RandomStatelessEjb java:app/weld-clustering-tests/RandomStatelessEjb!org.jboss.weld.tests.clustering.numberguess.decorator.RandomStatelessEjb java:module/RandomStatelessEjb!org.jboss.weld.tests.clustering.numberguess.decorator.RandomStatelessEjb java:global/weld-clustering-tests/RandomStatelessEjb java:app/weld-clustering-tests/RandomStatelessEjb java:module/RandomStatelessEjb 10:28:20,376 INFO [org.jboss.as.ejb3.deployment.processors.EjbJndiBindingsDeploymentUnitProcessor] (MSC service thread 1-2) JNDI bindings for session bean named EjbGameBean in deployment unit deployment "weld-clustering-tests.war" are as follows: java:global/weld-clustering-tests/EjbGameBean!org.jboss.weld.tests.clustering.numberguess.decorator.GameLocal java:app/weld-clustering-tests/EjbGameBean!org.jboss.weld.tests.clustering.numberguess.decorator.GameLocal java:module/EjbGameBean!org.jboss.weld.tests.clustering.numberguess.decorator.GameLocal java:global/weld-clustering-tests/EjbGameBean java:app/weld-clustering-tests/EjbGameBean java:module/EjbGameBean 10:28:20,707 INFO [org.jboss.weld.deployer] (MSC service thread 1-5) JBAS016005: Starting Services for CDI deployment: weld-clustering-tests.war 10:28:20,848 INFO [org.jboss.weld.Version] (MSC service thread 1-5) WELD-000900 1.1.8 (redhat) 10:28:20,950 INFO [org.jboss.as.osgi] (MSC service thread 1-5) JBAS011907: Register module: Module "deployment.weld-clustering-tests.war:main" from Service Module Loader 10:28:20,956 INFO [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016008: Starting weld service for deployment weld-clustering-tests.war 10:28:21,262 WARNING [org.jgroups.protocols.UDP] (ChannelService lifecycle - 1) send buffer of socket java.net.DatagramSocket@76f676f6 was set to 640KB, but the OS only allocated 131.07KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 10:28:21,264 WARNING [org.jgroups.protocols.UDP] (ChannelService lifecycle - 1) receive buffer of socket java.net.DatagramSocket@76f676f6 was set to 20MB, but the OS only allocated 131.07KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 10:28:21,264 WARNING [org.jgroups.protocols.UDP] (ChannelService lifecycle - 1) send buffer of socket java.net.MulticastSocket@77197719 was set to 640KB, but the OS only allocated 131.07KB. This might lead to performance problems. Please set your max send buffer in the OS correctly (e.g. net.core.wmem_max on Linux) 10:28:21,265 WARNING [org.jgroups.protocols.UDP] (ChannelService lifecycle - 1) receive buffer of socket java.net.MulticastSocket@77197719 was set to 25MB, but the OS only allocated 131.07KB. This might lead to performance problems. Please set your max receive buffer in the OS correctly (e.g. net.core.rmem_max on Linux) 10:28:21,266 ERROR [org.jboss.msc.service.fail] (ChannelService lifecycle - 1) MSC000001: Failed to start service jboss.jgroups.channel.ejb: org.jboss.msc.service.StartException in service jboss.jgroups.channel.ejb: java.lang.NullPointerException at org.jboss.as.clustering.msc.AsynchronousService$1.run(AsynchronousService.java:68) [jboss-as-clustering-common-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:897) [rt.jar:1.6.0] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:919) [rt.jar:1.6.0] at java.lang.Thread.run(Thread.java:736) [vm.jar:1.6.0] at org.jboss.threads.JBossThread.run(JBossThread.java:122) [jboss-threads-2.0.0.GA-redhat-1.jar:2.0.0.GA-redhat-1] Caused by: java.lang.NullPointerException at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:265) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:602) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.BARRIER.up(BARRIER.java:148) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.Discovery.up(Discovery.java:499) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.TP.fetchLocalAddresses(TP.java:1529) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.TP.start(TP.java:939) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.protocols.UDP.start(UDP.java:225) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.stack.ProtocolStack.startStack(ProtocolStack.java:938) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.JChannel.startStack(JChannel.java:841) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.JChannel.connect(JChannel.java:277) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jgroups.JChannel.connect(JChannel.java:261) [jgroups-3.0.9.Final-redhat-1.jar:3.0.9.Final-redhat-1] at org.jboss.as.clustering.jgroups.subsystem.ChannelService.start(ChannelService.java:44) [jboss-as-clustering-jgroups-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1] at org.jboss.as.clustering.msc.AsynchronousService$1.run(AsynchronousService.java:65) [jboss-as-clustering-common-7.1.2.Final-redhat-1.jar:7.1.2.Final-redhat-1] ... 4 more {noformat} This error happended only once during several runs with the same configuration.