[jboss-jira] [JBoss JIRA] (JGRP-1621) NPE on Locking.handleDeleteLockRequest

freeliuade freeliuade (JIRA) jira-events at lists.jboss.org
Thu Apr 18 04:58:55 EDT 2013 

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

freeliuade freeliuade commented on JGRP-1621:
---------------------------------------------

no much idea, it seems let the network traffic very busy will help reproduct it.

in my env, network bandwidth is 10M, one guy in our company using p2p tool downloads file, which taked up almost all bandwidth. next I found my thread is stick and then find this exception.


in the source code, it seems Locking.handView() didn't synchronized server_locks, not sure if this part result in this. from the log file, we can see the view get changed.
                
> NPE on Locking.handleDeleteLockRequest
> --------------------------------------
>
>                 Key: JGRP-1621
>                 URL: https://issues.jboss.org/browse/JGRP-1621
>             Project: JGroups
>          Issue Type: Bug
>    Affects Versions: 2.12.1
>            Reporter: freeliuade freeliuade
>            Assignee: Bela Ban
>             Fix For: 3.3
>
>
> meet NPE on Locking.handleDeleteLockRequest, this NPE seems happens on the network full bandwidth.
> and it seems this exception will result in a lock can't be unlock. 
> I'm pretty sure a locker has called unlock, but using LockService.printLocks() still can find the locker is be holding by a thread. 
> below is the log:
> 03:00:00,881 WARN  [GMS] hyliuds2-8321: not member of view [hyliuds1-33648|2] [hyliuds1-33648]; discarding it
> 03:00:00,890 WARN  [GMS] hyliuds2-30414: not member of view [hyliuds1-3567|4] [hyliuds1-3567, node2-9324, node2-33852]; discarding it
> 03:00:00,886 WARN  [GMS] hyliuds2-13134: not member of view [hyliuds1-13050|4] [hyliuds1-13050, node2-62142, node2-26805]; discarding it
> 03:00:00,924 WARN  [GMS] hyliuds2-10154: not member of view [hyliuds1-51819|4] [hyliuds1-51819, node2-14763, node2-26168]; discarding it
> 03:00:01,264 WARN  [GMS] jnp://10.101.7.172:1100: not member of view [jnp://10.101.7.24:1100|2] [jnp://10.101.7.24:1100]; discarding it
> 03:00:02,368 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-30414) am not member of view ([hyliuds1-3567|4] [hyliuds1-3567, node2-9324, node2-33852])
> 03:00:03,659 WARN  [GMS] hyliuds2-13134: failed to collect all ACKs (expected=4) for view MergeView::[node2-62142|5] [node2-62142, hyliuds2-13134, node2-26805, hyliuds1-13050], subgroups=[[hyliuds1-13050|4] [hyliuds1-13050, node2-62142, node2-26805], [hyliuds2-13134|3] [hyliuds2-13134]] after 2000ms, missing ACKs from [node2-62142, node2-26805]
> 03:00:06,019 INFO  [DomainManager] Installing App sla in domain DefaultDomain.
> 03:00:06,021 INFO  [DomainManager] App sla is installed in domain DefaultDomain.
> 03:00:19,321 INFO  [StateCache] Accept a new Node list "[jnp://10.101.7.24:1100, jnp://10.101.7.172:1100]"
> 03:00:33,586 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-30414) am not member of view ([hyliuds1-3567|4] [hyliuds1-3567, node2-9324, node2-33852])
> 03:00:50,634 INFO  [StateCache] Accept a new Node list "[jnp://10.101.7.24:1100, jnp://10.101.7.172:1100]"
> 03:01:03,585 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-30414) am not member of view ([hyliuds1-3567|4] [hyliuds1-3567, node2-9324, node2-33852])
> 03:01:30,951 INFO  [DomainManager] Installing App dojoclient in domain DefaultDomain.
> 03:01:30,971 INFO  [DomainManager] App dojoclient is installed in domain DefaultDomain.
> 03:01:41,450 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-10154) am not member of view ([hyliuds1-51819|4] [hyliuds1-51819, node2-14763, node2-26168])
> 03:01:49,799 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-30414) am not member of view ([hyliuds1-3567|4] [hyliuds1-3567, node2-9324, node2-33852])
> 03:02:02,298 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-10154) am not member of view ([hyliuds1-51819|4] [hyliuds1-51819, node2-14763, node2-26168])
> 03:03:33,370 WARN  [VIEW_SYNC] discarding view as I (hyliuds2-10154) am not member of view ([hyliuds1-51819|4] [hyliuds1-51819, node2-14763, node2-26168])
> 03:04:26,623 WARN  [GMS] hyliuds2-8321: not member of view [hyliuds1-33648|4] [hyliuds1-33648]; discarding it
> 03:04:35,922 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:35,922 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:37,106 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,227 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,227 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,227 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,228 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,228 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:53,527 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:54,460 INFO  [DomainManager] Deploying project "/apps/sla/projects/SLAAppletProject$Deployment" with release tag "TipOfTrunk" and deployment configuration "Deployment". The overwrite flag is true. The required Runtime Server is "DefaultPool/". The required Feed Server is "auto". The required Data Source for Runtime Server is "auto". The required Data Source for Feed Server is "auto".
> 03:04:54,837 INFO  [DomainManager] Project "/apps/sla/projects/SLAAppletProject$Deployment" has been dispatched with Runtime Server "DefaultPool/rs2", Feed Server "fs", Runtime Server Data Source "/vitria/m3o/datasource/DefaultDomain/datasource", Feed Server Data Source "/vitria/m3o/datasource/DefaultDomain/datasource".
> 03:04:54,986 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:54,987 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:04:56,972 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:03,650 INFO  [DomainManager] Data Source "/vitria/m3o/datasource/DefaultDomain/datasource" was deployed to RuntimeServer "DefaultPool/rs2".
> 03:05:03,692 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:03,692 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:04,387 INFO  [DomainManager] Data Source "/vitria/m3o/datasource/DefaultDomain/datasource" was deployed to FeedServer "fs".
> 03:05:04,956 INFO  [DomainManager] Feed "/apps/sla/projects/SLAAppletProject$Deployment/Vitria/Feed/EventSourceExceptionFeed" was deployed to FeedServer "fs".
> 03:05:05,000 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:05,001 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:05,994 INFO  [DomainManager] Feed "/apps/sla/projects/SLAAppletProject$Deployment/Feeds/KPINotifications" was deployed to FeedServer "fs".
> 03:05:06,991 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:11,047 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|5] [hyliuds2-8321]
> 03:05:13,003 INFO  [DomainManager] Project "/apps/sla/projects/SLAAppletProject$Deployment" successfully deployed on server "DefaultPool/rs2".
> 03:05:13,007 INFO  [DomainManager] Notify an event with type "Deploy".
> 04:57:15,746 WARN  [NAKACK] hyliuds2-10154: dropped message from hyliuds1-51819 (not in table [node2-14763, node2-26168, hyliuds2-10154]), view=[node2-14763|6] [node2-14763, hyliuds2-10154, node2-26168]
> 04:57:15,785 WARN  [NAKACK] hyliuds2-10154: dropped message from hyliuds1-51819 (not in table [node2-14763, node2-26168, hyliuds2-10154]), view=[node2-14763|6] [node2-14763, hyliuds2-10154, node2-26168]
> 04:57:19,956 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|7] [hyliuds2-8321]
> 04:57:35,009 WARN  [NAKACK] hyliuds2-8321: dropped message from hyliuds1-33648 (not in table [hyliuds2-8321]), view=[hyliuds2-8321|7] [hyliuds2-8321]
> 04:57:43,024 ERROR [UNICAST] couldn't deliver message [dst: hyliuds2-8321, src: hyliuds1-33648 (3 headers), size=95 bytes, flags=DONT_BUNDLE]
> java.lang.NullPointerException
> 	at org.jgroups.protocols.Locking.handleDeleteLockRequest(Locking.java:505)
> 	at org.jgroups.protocols.Locking.up(Locking.java:243)
> 	at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java:150)
> 	at org.jgroups.protocols.FRAG2.up(FRAG2.java:189)
> 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
> 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
> 	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:891)
> 	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:246)
> 	at org.jgroups.protocols.VIEW_SYNC.up(VIEW_SYNC.java:170)
> 	at org.jgroups.protocols.UNICAST.handleDataReceived(UNICAST.java:613)
> 	at org.jgroups.protocols.UNICAST.up(UNICAST.java:294)
> 	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:703)
> 	at org.jgroups.protocols.BARRIER.up(BARRIER.java:119)
> 	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:133)
> 	at org.jgroups.protocols.FD_ALL.up(FD_ALL.java:177)
> 	at org.jgroups.protocols.FD.up(FD.java:275)
> 	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:275)
> 	at org.jgroups.protocols.MERGE2.up(MERGE2.java:209)
> 	at org.jgroups.protocols.Discovery.up(Discovery.java:293)
> 	at org.jgroups.protocols.PING.up(PING.java:69)
> 	at org.jgroups.protocols.TP.passMessageUp(TP.java:1109)
> 	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1665)
> 	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1647)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
> 	at java.lang.Thread.run(Thread.java:722)

--
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

More information about the jboss-jira mailing list