jackrabbit-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Torgeir Veimo <torg...@pobox.com>
Subject Re: "Unable to lock node. Node has pending changes: /counter"
Date Tue, 20 Jun 2006 08:21:43 GMT
On Mon, 2006-06-19 at 16:56 +0200, Marcel Reutegger wrote:
> On 6/19/06, Torgeir Veimo <torgeir@pobox.com> wrote:
> > Would it be correct to call refresh(false) on the counter node in case
> > of an exception? I only ever modify the value property when the node is
> > created and in the generateNewResourceId() method.
> 
> yes, you should definitively handle that case. but after having a
> second look at your code I realized that the counter node actually
> doesn't get modified in the run method. It is only the property that
> changes. So it seems there must be some code that modifies the counter
> node outside of the Locked.run() method.
> 
> there are also some test cases that show how to use the utility:
> http://svn.apache.org/repos/asf/jackrabbit/trunk/jackrabbit/src/test/java/org/apache/jackrabbit/core/LockTest.java
> 
> Those test cases run fine on my checkout. and one of them
> (LockTest.testSequence) does the same as your generateNewResourceId()
> method, it increments a counter property.

I copy&pasted that code into mine, and run the testSequence code on am
empty repository. I made some slight changes, and now that code gives
the same exceptions. Notice how I changed retrieving the session and the
lack of session logout. I guess this is where the problem lies.

Do the sequence have to run with its own session?

    protected void setupRepository() {
        try {
            // add default nen and crm namespace
            Workspace ws = session.getWorkspace();
            String [] prefixes =
ws.getNamespaceRegistry().getPrefixes();
            java.util.Arrays.sort(prefixes);
            if (java.util.Arrays.binarySearch(prefixes, "nen") < 0) {
                ws.getNamespaceRegistry().registerNamespace("nen",
"http://netenviron.com/nen/1.0");
                ws.getNamespaceRegistry().registerNamespace("crm",
"http://netenviron.com/crm/1.0");
            }
            
            testSequence();
            
        } catch (javax.jcr.RepositoryException re) {
            log.error("unable to create lock node; ", re);
        }
    }

    private static final int NUM_THREADS = 100;
    private static final int NUM_CHANGES = 10;
    private static final int NUM_VALUE_GETS = 10;
    
    public void testSequence() throws javax.jcr.RepositoryException {
        
        final String nodeName1 = "testnode";
        final String mixLockable = "mix:lockable";
        Node testRootNode = session.getRootNode();
        
        log.debug("\n\n entering testSequence..\n\n");
        
        final Node counter = testRootNode.addNode(nodeName1);
        counter.setProperty("value", 0);
        counter.addMixin(mixLockable);
        testRootNode.save();
        
        final List worker = new ArrayList();
        for (int i = 0; i < NUM_THREADS; i++) {
            worker.add(new Thread() {
                
                private final int threadNumber = worker.size();
                
                public void run() {
                    Session s;
                    //try {
                        s = session; //helper.getSuperuserSession();
                    //} catch (RepositoryException e) {
                    //    return;
                    //}
                    try {
                        for (int i = 0; i < NUM_VALUE_GETS; i++) {
                            Node n = (Node)
s.getItem(counter.getPath());
                            long currentValue = ((Long) new Locked() {
                                protected Object run(Node n) throws
javax.jcr.RepositoryException {
                                    Property seqProp =
n.getProperty("value");
                                    long value = seqProp.getLong();
                                    seqProp.setValue(++value);
                                    seqProp.save();
                                    return new Long(value);
                                }
                            }.with(n, false)).longValue();
                            log.debug("Thread" + threadNumber + ": got
sequence number: " + currentValue);
                            // do a random wait
                            Thread.sleep(new Random().nextInt(100));
                        }
                    } catch (javax.jcr.RepositoryException e) {
                        log.debug("exception while running code with
lock:" + e.getMessage());
                    } catch (InterruptedException e) {
                        log.debug(Thread.currentThread() + " interrupted
while waiting for lock");
                    } finally {
                        //s.logout();
                    }
                }
            });
        }
        
        for (Iterator it = worker.iterator(); it.hasNext(); ) {
            ((Thread) it.next()).start();
        }
        
        for (Iterator it = worker.iterator(); it.hasNext(); ) {
            try {
                ((Thread) it.next()).join();
            } catch (InterruptedException e) {
                e.printStackTrace();
            }
        }
    }

The output from this program is;

09:20:19,473 DEBUG JackrabbitRepositoryDAO  -

 entering testSequence..


09:20:19,473 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5
09:20:19,474 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5
09:20:19,474 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}primaryType
09:20:19,474 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}primaryType
09:20:19,476 DEBUG HierarchyManagerImpl  - failed to build path of
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{}value
09:20:19,476 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{}value
09:20:19,476 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{}value
09:20:19,477 DEBUG NodeState  - listener already registered:
org.apache.jackrabbit.core.CachingHierarchyManager@16509fe
09:20:19,479 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}mixinTypes
09:20:19,479 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}mixinTypes
09:20:19,493 DEBUG SharedItemStateManager  - persisting change log
{#addedStates=4, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0}
took 11ms
09:20:19,494 DEBUG ObservationManagerFactory  - notifying 3 synchronous
listeners.
09:20:19,513 DEBUG SearchManager  - onEvent: indexing started
09:20:19,524 DEBUG NamespaceMappings  - adding new namespace mapping: 4
->
09:20:19,527 DEBUG SearchManager  - onEvent: indexing finished in 14 ms.
09:20:19,531 DEBUG ObservationManagerFactory  - got EventStateCollection
09:20:19,532 DEBUG ObservationManagerFactory  - event delivery to 1
consumers started...
09:20:19,532 DEBUG ObservationManagerFactory  - event delivery finished.
09:20:19,555 DEBUG HierarchyManagerImpl  - failed to build path of
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,555 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,555 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,556 DEBUG HierarchyManagerImpl  - failed to build path of
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockIsDeep
09:20:19,556 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockIsDeep
09:20:19,556 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockIsDeep
09:20:19,563 DEBUG SharedItemStateManager  - persisting change log
{#addedStates=2, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0}
took 4ms
09:20:19,563 DEBUG ObservationManagerFactory  - notifying 3 synchronous
listeners.
09:20:19,563 DEBUG SearchManager  - onEvent: indexing started
09:20:19,565 DEBUG SearchManager  - onEvent: indexing finished in 2 ms.
09:20:19,565 DEBUG ObservationManagerFactory  - got EventStateCollection
09:20:19,565 DEBUG ObservationManagerFactory  - event delivery to 1
consumers started...
09:20:19,565 DEBUG ObservationManagerFactory  - event delivery finished.
09:20:19,569 DEBUG ItemManager  - created item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{}value
09:20:19,569 DEBUG ItemManager  - caching item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{}value
09:20:19,580 DEBUG SharedItemStateManager  - persisting change log
{#addedStates=0, #modifiedStates=1, #deletedStates=0, #modifiedRefs=0}
took 10ms
09:20:19,581 DEBUG ObservationManagerFactory  - notifying 3 synchronous
listeners.
09:20:19,581 DEBUG SearchManager  - onEvent: indexing started
09:20:19,581 DEBUG SearchManager  - onEvent: indexing finished in 0 ms.
09:20:19,581 DEBUG ObservationManagerFactory  - got EventStateCollection
09:20:19,581 DEBUG ObservationManagerFactory  - event delivery to 8
consumers started...
09:20:19,582 DEBUG ObservationManagerFactory  - event delivery finished.
09:20:19,584 DEBUG ItemManager  - invalidated item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,584 DEBUG ItemManager  - removing item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner from cache
09:20:19,584 DEBUG ItemManager  - invalidated item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockIsDeep
09:20:19,584 DEBUG ItemManager  - removing item
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockIsDeep from cache
09:20:19,585 DEBUG HierarchyManagerImpl  - failed to build path of
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,585 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:failed to build path of
f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner: f37ab406-beee-45be-b4d1-dc42d5ac94e5/{http://www.jcp.org/jcr/1.0}lockOwner
09:20:19,586 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,590 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,591 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,591 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,589 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,591 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,592 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,592 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,589 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,592 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,592 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode
09:20:19,593 DEBUG JackrabbitRepositoryDAO  - exception while running
code with lock:Unable to lock node. Node has pending changes: /testnode
09:20:19,588 DEBUG NodeImpl  - Unable to lock node. Node has pending
changes: /testnode

-- 
Torgeir Veimo <torgeir@pobox.com>


Mime
View raw message