EventListener questions

[eldaryus]

Hi,

I've been trying to use EventListeners with ModeShape 3.8 and I have several questions regarding it:

1. ObservationManager.addEventListener JavaDoc says that nodeTypeName restrictions

are "ANDed" together. In other words, for a particular node to be "listened to" it must meet all the restrictions

  however JCR 2.0 spec says that

Only events whose associated parent node is of one of the node types in the nodeTypeNames String array will be received.

That is, restricions are ORed. Which one is correct? It seems that ModeShape implements it as in the spec.

2. noLocal restriction doesn't seem to be working in ModeShape. I've created a dedicated session for event handling and registered the listener via eventSession.getWorkspace().getObservationManager() with noLocal = true

However, when I'm updating the repository via the other session, the event doesn't get triggered at all.

I tried to debug this a little and the session comparison in JcrObservationManager is being done using session.context().getProcessId(), however this parameter is the same for all the sessions that I create. As far as I understand, whenever a new session is created, an ExecutionContext is copied from the repository one, and it seems that the processId gets copied too, so perhaps this is the reason?

3. My listener creates additional nodes (using the eventSession), and this triggers events. Since I can't use noLocal flag, JcrObservationManager tries to see if it should notify my listeners about these nodes creation. However, at this point I'm getting the following exception:

javax.jcr.PathNotFoundException: No node exists at path '/repository/newNode' in workspace "default"

    at org.modeshape.jcr.JcrSession.cachedNode(JcrSession.java:610)

    at org.modeshape.jcr.JcrSession.node(JcrSession.java:640)

    at org.modeshape.jcr.JcrSession.node(JcrSession.java:659)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.acceptBasedOnNodeTypeName(JcrObservationManager.java:1072)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.shouldReject(JcrObservationManager.java:996)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.processChange(JcrObservationManager.java:852)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.notify(JcrObservationManager.java:828)

    at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetDispatcher.call(RepositoryChangeBus.java:227)

    at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetDispatcher.call(RepositoryChangeBus.java:209)

    at java.util.concurrent.FutureTask.run(FutureTask.java:266)

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

    at java.lang.Thread.run(Thread.java:745)

Is this expected behaviour? Am I allowed to create new nodes in the Event Listeners?

[rhauch]

I've been trying to use EventListeners with ModeShape 3.8 and I have several questions regarding it:

1. ObservationManager.addEventListener JavaDoc says that nodeTypeName restrictions

are "ANDed" together. In other words, for a particular node to be "listened to" it must meet all the restrictions

  however JCR 2.0 spec says that

Only events whose associated parent node is of one of the node types in the nodeTypeNames String array will be received.

That is, restricions are ORed. Which one is correct? It seems that ModeShape implements it as in the spec.

In the rare case where there is a discrepancy between the spec and the JavaDoc, we follow the spec.

2. noLocal restriction doesn't seem to be working in ModeShape. I've created a dedicated session for event handling and registered the listener via eventSession.getWorkspace().getObservationManager() with noLocal = true

However, when I'm updating the repository via the other session, the event doesn't get triggered at all.

I tried to debug this a little and the session comparison in JcrObservationManager is being done using session.context().getProcessId(), however this parameter is the same for all the sessions that I create. As far as I understand, whenever a new session is created, an ExecutionContext is copied from the repository one, and it seems that the processId gets copied too, so perhaps this is the reason?

When you register a listener using Session A, then as soon as Session A is terminated (via logout) the listener will be unregistered. After all, the session on which the listener was created is no longer usable. So most people use a single long-lived session that your application uses only to register event listeners.

So if this is the case, then "noLocal" means that the listener will never see events generated by the long-lived session. But really, that long-lived session should not be used by anything and thus no events will ever be generated by it. Remember that JCR sessions are not thread safe (they are stateful), so you can't share sessions.

[eldaryus]

Hi Randall,

When you register a listener using Session A, then as soon as Session A is terminated (via logout) the listener will be unregistered. After all, the session on which the listener was created is no longer usable. So most people use a single long-lived session that your application uses only to register event listeners.

So if this is the case, then "noLocal" means that the listener will never see events generated by the long-lived session. But really, that long-lived session should not be used by anything and thus no events will ever be generated by it. Remember that JCR sessions are not thread safe (they are stateful), so you can't share sessions.

Yes, that's how I thought noLocal should work - what I've been doing is registering long-lived "event listening" session that's not used for anything else. However, when registering noLocal listener with this session, events from the other sessions are also ignored by this listener.

I sent my initial post prematurely and have since updated it with the third question - could you take a look at it as well please?

[hchiorean]

noLocal should work as far as the other sessions are concerned. I've opened [MODE-2268] The JcrObservationManager doesn't filter local/nonLocal events correctly - JBoss Issue Tracker to track the issue.

Regarding the exception, that's probably another issue altogether. Can you please create a test case or something similar that would help us reproduce it and then open a JIRA ? Our observation-related tests are in modeshape/modeshape-jcr/src/test/java/org/modeshape/jcr/JcrObservationManagerTest.java at master · ModeShape/modeshape ·…

[eldaryus]

Thanks, Horia.

Will try definitely try to create a test case for this problem.

[eldaryus]

HI,

It seems that the problem appears when I'm using JTA transactions and create a relatively large amount of nodes within a single transaction.

I have written a simple app to reproduce this - you can find it at eyusupov/modetest · GitHub.

To run it, execute:

$ mvn clean install

$ java -classpath 'target/modetest-1.0-SNAPSHOT.jar:target/lib/*' com.okasamastarr.ModeTest

It will create a log file called modetest.log and will also display logs on the standard output.

Here is the example of the error that I'm seeing.

31 Jul 2014 00:40:49,149 25034 [modeshape-event-dispatcher-3-thread-6] ERROR org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter  - Error checking primary type 'null' with mixins of 'null' against type names of '[test:test]'

javax.jcr.PathNotFoundException: No node exists at path '/testp/test7296' in workspace "default"

    at org.modeshape.jcr.JcrSession.cachedNode(JcrSession.java:609)

    at org.modeshape.jcr.JcrSession.node(JcrSession.java:639)

    at org.modeshape.jcr.JcrSession.node(JcrSession.java:658)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.acceptBasedOnNodeTypeName(JcrObservationManager.java:1072)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.shouldReject(JcrObservationManager.java:995)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.processChange(JcrObservationManager.java:852)

    at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.notify(JcrObservationManager.java:828)

    at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetDispatcher.call(RepositoryChangeBus.java:227)

    at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetDispatcher.call(RepositoryChangeBus.java:209)

    at java.util.concurrent.FutureTask.run(FutureTask.java:266)

    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

    at java.lang.Thread.run(Thread.java:745)

[rhauch]

Might it be the case that there are so many events that the '/testp/test7296' node has been removed before the event listener can process the event?

[eldaryus]

I don't delete any nodes in this test, just add them. Also, I could reproduce the problem with just 1000 nodes.

I took the large number of nodes so that the transaction commit would take some time, as I noticed that when the error appears, event handling starts before the adding nodes transaction  has completed.

Like this:

31 Jul 2014 02:10:21,351 0 [main] INFO com.okasamastarr.ModeTest  - Initializing engine

31 Jul 2014 02:10:21,377 26 [main] INFO com.okasamastarr.ModeTest  - Starting engine

31 Jul 2014 02:10:21,548 197 [main] INFO com.okasamastarr.ModeTest  - Deploying engine

31 Jul 2014 02:10:21,747 396 [main] INFO com.okasamastarr.ModeTest  - Registering listener

31 Jul 2014 02:10:24,440 3089 [main] INFO com.okasamastarr.ModeTest  - Registered listener

31 Jul 2014 02:10:24,447 3096 [main] DEBUG com.okasamastarr.ModeTest  - Starting transaction

31 Jul 2014 02:10:24,656 3305 [main] DEBUG com.okasamastarr.ModeTest  - Saving session

>>>>> Here the event hadling starts:

31 Jul 2014 02:10:25,022 3671 [main] DEBUG com.okasamastarr.ModeTest  - Commiting transaction

31 Jul 2014 02:10:25,337 3986 [modeshape-event-dispatcher-3-thread-6] ERROR org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter  - Error checking primary type 'null' with mixins of 'null' against type names of '[test:test]'

javax.jcr.PathNotFoundException: No node exists at path '/testp' in workspace "default"

        at org.modeshape.jcr.JcrSession.cachedNode(JcrSession.java:609)

>>>>> Here the transaction has been commited

31 Jul 2014 02:10:25,359 4008 [main] DEBUG com.okasamastarr.ModeTest  - Transaction commited

[eldaryus]

Hi, is there anything else I could provide to help investigate this issue?

[jacobilsoe]

Hi. I have the exact same problem with the javax.jcr.PathNotFoundException. I have a few nodes in total and try to delete one of them. The node is correctly deleted but I get this error:

10:06:04,511 ERROR [org.modeshape.jcr.JcrObservationManager] (modeshape-event-dispatcher-4-thread-8) Error checking primary type 'null' with mixins of 'null' against type names of '[swmix:plan]': javax.jcr.PathNotFoundException: No node exists at path '/PLANS/P1' in workspace "default"

        at org.modeshape.jcr.JcrSession.cachedNode(JcrSession.java:623) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrSession.node(JcrSession.java:655) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrSession.node(JcrSession.java:674) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrObservationManager$ChangeSetConverter.acceptBasedOnNodeTypeName(JcrObservationManager.java:1115) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrObservationManager$ChangeSetConverter.shouldRejectChange(JcrObservationManager.java:1043) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrObservationManager$ChangeSetConverter.processChange(JcrObservationManager.java:887) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrObservationManager$ChangeSetConverter.convert(JcrObservationManager.java:866) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.notify(JcrObservationManager.java:374) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetListenerConsumerAdapter.consume(RepositoryChangeBus.java:161) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetListenerConsumerAdapter.consume(RepositoryChangeBus.java:155) [modeshape-jcr-4.0.0.Final.jar:4.0.0.Final]

        at org.modeshape.common.collection.ring.RingBuffer$ConsumerRunner.run(RingBuffer.java:462) [modeshape-common-4.0.0.Final.jar:4.0.0.Final]

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_65]

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_65]

        at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_65]

I am using ModeShape 4.0.0 as you can see from the stacktrace.

Any thoughts?

[hchiorean]

It seems somehow that an event is received by a listener even though the parent of the node for which the event was sent has been deleted (and removing the parent should remove all its children recursively).

If you can reproduce this in a test case, feel free to open a JIRA. Thanks.

EDIT: btw, in case you're using multiple threads for writing & reading nodes, make sure your infinispan cache uses PESSIMISTIC locking with READ_COMMITTED isolation.

[hchiorean]

It's actually easy to reproduce this one, so I've opened: [MODE-2379] Unexpected exception raised when listeners are registered for certain node types and parent nodes are remove…