[jbosscache-issues] [JBoss JIRA] Created: (JBCACHE-1584) NodeInvocationDelegate.addChild(Fqn) can return null in some circumstances contrary to JavaDoc for Node.addChild(Fqn)

Friday, 4 June 2010

NodeInvocationDelegate.addChild(Fqn) can return null in some circumstances contrary to
JavaDoc for Node.addChild(Fqn)
---------------------------------------------------------------------------------------------------------------------

                 Key: JBCACHE-1584
                 URL: https://jira.jboss.org/browse/JBCACHE-1584
             Project: JBoss Cache
          Issue Type: Bug
      Security Level: Public (Everyone can see)
          Components: Locking
    Affects Versions: 3.1.0.GA
            Reporter: Andrew Duckworth
            Assignee: Manik Surtani

NodeInvocationDelegate.addChild(Fqn) can return null in some circumstances:

It seems if in a multi-threaded environment with a slow JDBC cache loader the following
sequence can occur:

1. Thread 1 calls NodeInvocationDelegate.addChild(Fqn), node does not exist and is created
locally

       getChild() == null
       put(fqn)      // node now exists on DB

2. Thread 2 calls NodeInvocationDelegate.removeChild(Fqn)

     results in node being deleted from DB

3. Thread 1 

    returns getChild(fqn) as the result of the add, however this propagates all the way
down to the cache loader and null is returned violating the contract of addChild which
indicates a non-null return value.

see the following log4j log entries for more details:

[Entry id=40225, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40226, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40227, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 is false
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40228, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40229, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40230, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 is false
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40231, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.invocation.NodeInvocationDelegate, message=Child is null;
creating.
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40232, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=loadNode
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40233, date=2010-06-04 14:43:24,983, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT node FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40234, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=put
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 attr={}
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40235, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40236, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40237, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 is false
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40238, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=addNewSubtree
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 attr={}
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40239, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=insertNode
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 dataMap={}
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40240, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[INSERT INTO jbosscache (fqn, node, parent) SELECT ?, ?, ? FROM jbosscache_D WHERE NOT
EXISTS (SELECT fqn FROM jbosscache WHERE fqn = ?)]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40241, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40242, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40243, date=2010-06-04 14:43:24,998, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache is true
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40244, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40245, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=Executing SQL statement [SELECT '1' FROM jbosscache WHERE fqn = ?] with
params [/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40246, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 is true
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40247, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=loadNode
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40248, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=Executing SQL statement [SELECT node FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40249, date=2010-06-04 14:43:24,998, level=DEBUG,
thread=FestivalScheduler_Worker-1, emitter=org.jboss.cache.loader.BatchJDBCCacheLoader,
message=Executing SQL statement [DELETE FROM jbosscache WHERE fqn = ? OR fqn LIKE ? ESCAPE
'^'] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503],
[/com.sandstone^_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503/%]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:workflow_identity
thd:91]]></log4j:NDC>
]
[Entry id=40250, date=2010-06-04 14:43:25,014, level=INFO, thread=WebContainer : 15,
emitter=com.sandstone_tech.workflow.UPGRADING_WORKFLOW_SPECIFICATION, message=Upgrading
the workflow specification for instance com.sandstone_tech.workflow.WorkflowInstImpl: name
= FldFiordland: id = 16343 from version 352 to 357.
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:oceaniatst\aumlafulfil042
sess:b32l3DIPtxjOS8yE2pjRNta thd:1771]]></log4j:NDC>
]
[Entry id=40251, date=2010-06-04 14:43:25,170, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.invocation.NodeInvocationDelegate, message=Created.  Now getting
again.
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40252, date=2010-06-04 14:43:25,170, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40253, date=2010-06-04 14:43:25,170, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=Executing SQL statement
[SELECT '1' FROM jbosscache WHERE fqn = ?] with params
[/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503]
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40254, date=2010-06-04 14:43:25,170, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.loader.BatchJDBCCacheLoader, message=exists
name=/com.sandstone_tech.workflow.WorkflowManager.TaskOwnershipCache/4440503 is false
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40255, date=2010-06-04 14:43:25,170, level=DEBUG, thread=WebContainer : 19,
emitter=org.jboss.cache.invocation.NodeInvocationDelegate, message=Got child null
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
]
[Entry id=40256, date=2010-06-04 14:43:25,170, level=ERROR, thread=WebContainer : 19,
emitter=com.sandstone_tech.framework.cluster.jbosscache.NodePerKeyMap, message=Unable to
put 4,440,503
<log4j:NDC><![CDATA[sid:7564@WASAUQAADT020 user:auser
sess:9RJ3MT6YXP5BJj57v4NYnaA thd:1829]]></log4j:NDC>
<log4j:throwable><![CDATA[java.lang.NullPointerException
	at
com.sandstone_tech.framework.cluster.jbosscache.NodePerKeyMap.put0(NodePerKeyMap.java:207)
	at
com.sandstone_tech.framework.cluster.jbosscache.NodePerKeyMap.put(NodePerKeyMap.java:183)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
https://jira.jboss.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

[jbosscache-issues] [JBoss JIRA] Created: (JBCACHE-1584) NodeInvocationDelegate.addChild(Fqn) can return null in some circumstances contrary to JavaDoc for Node.addChild(Fqn)