1 Reply Latest reply on Mar 3, 2017 2:05 AM by hchiorean

    errorProcessingEvent? "Unexpected error while processing the event"

    kefo

      Hello,

       

      We're seeing errors in our application log that appear to be modeshape related [1].

       

      INFO 22:19:53.817 (FedoraLdp) PUT resource 'prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650' ... ERROR 22:19:54.590 (RepositoryChangeBus) Unexpected error while processing the event 'Save by 'bypassAdmin' at 2017-02-17T22:19:54.095-06:00 with user data = {org.modeshape.jcr.observation.userdata={"baseUrl":"https://aicdamstest08.artic.edu/fcrepo/rest/","userAgent":"Faraday v0.9.2"}} in repository with key '927fdb8' and workspace 'defau lt'   Added node '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4' at "/{}prod/{}da/{}39/{}e4" under '87a0a8c7505d64531aa359-9985-46a6-8c0c-3a453b48c44c'   Added property {http://www.jcp.org/jcr/1.0}createdBy to node '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4' at path /{}prod/{}da/{}39/{}e4 with values:{http://www.jcp.org/jcr/1.0}createdBy = bypassAdmin   Added property {http://www.jcp.org/jcr/1.0}primaryType to node '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4' at path /{}prod/{}da/{}39/{}e4 with values:{http://www.jcp.org/jcr/1.0}primaryType = {http://www.jcp.org/jcr/nt/1.0}folder   Added property {http://www.jcp.org/jcr/1.0}created to node '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4' at path /{}prod/{}da/{}39/{}e4 with values:{http://www.jcp.org/jcr/1.0}created = 2017-02-17T22:19:53.820-06:00   Added property {http://www.jcp.org/jcr/1.0}mixinTypes to node '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4' at path /{}prod/{}da/{}39/{}e4 with values:{http://www.jcp.org/jcr/1.0}mixinTypes = [{http://fedora.info/definitions/v4/repository#}Pairtree]   Added node '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6' at "/{}prod/{}da/{}39/{}e4/{}3d" under '87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4'   Added property {http://www.jcp.org/jcr/1.0}createdBy to node '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6' at path /{}prod/{}da/{}39/{}e4/{}3d with values:{http://www.jcp.org/jcr/1.0}createdBy = bypassAdmin   Added property {http://www.jcp.org/jcr/1.0}primaryType to node '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6' at path /{}prod/{}da/{}39/{}e4/{}3d with values:{http://www.jcp.org/jcr/1.0}primaryType = {http://www.jcp.org/jcr/nt/1.0}folder   Added property {http://www.jcp.org/jcr/1.0}created to node '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6' at path /{}prod/{}da/{}39/{}e4/{}3d with values:{http://www.jcp.org/jcr/1.0}created = 2017-02-17T22:19:53.820-06:00   Added property {http://www.jcp.org/jcr/1.0}mixinTypes to node '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6' at path /{}prod/{}da/{}39/{}e4/{}3d with values:{http://www.jcp.org/jcr/1.0}mixinTypes = [{http://fedora.info/definitions/v4/repository#}Pairtree]   Added node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650" under '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6'   Added property {http://www.jcp.org/jcr/1.0}lastModifiedBy to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}lastModifiedBy = bypassAdmin   Added property {http://www.jcp.org/jcr/1.0}uuid to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}uuid = 471df0cf-589d-430e-b516-cfb0fbf34fa7   Added property {http://definitions.artic.edu/ontology/1.0/}uid to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://definitions.artic.edu/ontology/1.0/}uid = [SI-CI286548^X^^^Xhttp://www.w3.org/2001/XMLSchema#string]   Added property {http://definitions.artic.edu/ontology/1.0/}documentType to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://definitions.artic.edu/ontology/1.0/}documentType = [http://definitions.artic.edu/doctypes/Imaging^X^^^XURI]   Added property {info:fedora/fedora-system:def/model#}hasModel to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{info:fedora/fedora-system:def/model#}hasModel = [GenericWork^X^^^Xhttp://www.w3.org/2001/XMLSchema#string]   Added property {http://www.w3.org/2004/02/skos/core#}prefLabel to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.w3.org/2004/02/skos/core#}prefLabel = [AKevinSpecial^X^^^Xhttp://www.w3.org/2001/XMLSchema#string]   Added property {http://id.loc.gov/vocabulary/relators/}dpt_ref to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://id.loc.gov/vocabulary/relators/}dpt_ref = [87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051]   Added property {http://purl.org/dc/terms/}dateSubmitted to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://purl.org/dc/terms/}dateSubmitted = [2017-02-18T04:19:53.591856344+00:00^X^^^Xhttp://www.w3.org/2001/XMLSchema#dateTime]   Added property {http://definitions.artic.edu/ontology/1.0/}status_ref to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://definitions.artic.edu/ontology/1.0/}status_ref = [87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d]   Added property {http://www.jcp.org/jcr/1.0}createdBy to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}createdBy = bypassAdmin   Added property {http://www.jcp.org/jcr/1.0}primaryType to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}primaryType = {http://www.jcp.org/jcr/nt/1.0}folder   Added property {http://fedora.info/definitions/v4/repository#}lastModified to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://fedora.info/definitions/v4/repository#}lastModified = 2017-02-18T04:19:53.820Z   Added property {http://www.jcp.org/jcr/1.0}created to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}created = 2017-02-17T22:19:53.820-06:00   Added property {http://www.jcp.org/jcr/1.0}mixinTypes to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}mixinTypes = [{http://definitions.artic.edu/ontology/1.0/type/}Asset, {http://fedora.info/definitions/v4/repository#}Container, {http://definitions.artic.edu/ontology/1.0/type/}Resource, {http://projecthydra.org/works/models#}Work, {http://definitions.artic.edu/ontology/1.0/type/}StillImage, {http://fedora.info/definitions/v4/repository#}Resource, {http://pcdm.org/models#}Object]   Added property {http://www.jcp.org/jcr/1.0}lastModified to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Added property {http://definitions.artic.edu/ontology/1.0/}deptCreated_ref to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://definitions.artic.edu/ontology/1.0/}deptCreated_ref = [87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f]   Added property {http://www.w3.org/ns/auth/acl#}accessControl_ref to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.w3.org/ns/auth/acl#}accessControl_ref = [87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592]   Added property {http://definitions.artic.edu/ontology/1.0/}documentSubType1 to node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://definitions.artic.edu/ontology/1.0/}documentSubType1 = [http://definitions.artic.edu/doctypes/ObjectPhotography^X^^^XURI]   Changed property {http://fedora.info/definitions/v4/repository#}lastModified on node '87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb' at path /{}prod from:{http://fedora.info/definitions/v4/repository#}lastModified = 2017-02-18T04:19:53.436Z to:{http://fedora.info/definitions/v4/repository#}lastModified = 2017-02-18T04:19:53.817Z   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb' at path /{}prod from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.437-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f' at path /{}prod/{}88/{}94/{}a0/{}f6/{}8894a0f6-ab34-3f23-60a0-353ea1ba4242 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-01-18T16:15:12.151-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Changed node '87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f' at "/{}prod/{}88/{}94/{}a0/{}f6/{}8894a0f6-ab34-3f23-60a0-353ea1ba4242"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d' at path /{}prod/{}58/{}f0/{}0e/{}ca/{}58f00eca-c398-02f0-f9bb-6b2b6105c0ef from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:49.640-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Changed node '87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d' at "/{}prod/{}58/{}f0/{}0e/{}ca/{}58f00eca-c398-02f0-f9bb-6b2b6105c0ef"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051' at path /{}prod/{}f6/{}db/{}51/{}2a/{}f6db512a-25d3-6290-e0c9-29c7fea7e795 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-01-17T22:01:07.519-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Changed node '87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051' at "/{}prod/{}f6/{}db/{}51/{}2a/{}f6db512a-25d3-6290-e0c9-29c7fea7e795"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.437-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:53.820-06:00   Changed node '87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592' at "/{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d" changed 9 nodes:   87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6   87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb   87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f   87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592   87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051   87a0a8c7505d64531aa359-9985-46a6-8c0c-3a453b48c44c   87a0a8c7505d64640f93e3-7cfc-4c40-bab2-48a429660cb4   87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d   87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7 ' with the sequence number '7099' java.lang.NullPointerException: null         at java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:193)         at java.util.stream.SpinedBuffer$1Splitr.tryAdvance(SpinedBuffer.java:332)         at java.util.stream.ReferencePipeline.forEachWithCancel(ReferencePipeline.java:126)         at java.util.stream.AbstractPipeline.copyIntoWithCancel(AbstractPipeline.java:498)         at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:485)         at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)         at java.util.stream.MatchOps$MatchOp.evaluateSequential(MatchOps.java:230)         at java.util.stream.MatchOps$MatchOp.evaluateSequential(MatchOps.java:196)         at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)         at java.util.stream.ReferencePipeline.anyMatch(ReferencePipeline.java:449)         at org.fcrepo.kernel.modeshape.observer.DefaultFilter.test(DefaultFilter.java:52)         at org.fcrepo.kernel.modeshape.observer.DefaultFilter.test(DefaultFilter.java:45)         at com.google.common.collect.Iterators$6.computeNext(Iterators.java:617)         at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:145)         at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:140)         at java.util.Iterator.forEachRemaining(Iterator.java:115)         at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)         at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)         at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)         at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)         at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)         at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499)         at org.fcrepo.kernel.modeshape.observer.eventmappings.AllNodeEventsOneEvent.apply(AllNodeEventsOneEvent.java:68)         at org.fcrepo.kernel.modeshape.observer.eventmappings.AllNodeEventsOneEvent.apply(AllNodeEventsOneEvent.java:48)         at org.fcrepo.kernel.modeshape.observer.SimpleObserver.onEvent(SimpleObserver.java:222)         at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.notify(JcrObservationManager.java:294)         at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetListenerConsumerAdapter.consume(RepositoryChangeBus.java:207)         at org.modeshape.jcr.bus.RepositoryChangeBus$ChangeSetListenerConsumerAdapter.consume(RepositoryChangeBus.java:201)         at org.modeshape.common.collection.ring.RingBuffer$ConsumerRunner.run(RingBuffer.java:466)         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) INFO 22:19:54.607 (FedoraLdp) HEAD for: prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650 INFO 22:19:54.608 (FedoraLdp) HEAD for: prod/cb/17/43/87/cb174387-0f6f-44ef-8495-951955ab59ad INFO 22:19:54.625 (FedoraLdp) GET resource 'prod/cb/17/43/87/cb174387-0f6f-44ef-8495-951955ab59ad' INFO 22:19:54.627 (FedoraLdp) HEAD for: prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650/list_source INFO 22:19:54.646 (FedoraLdp) HEAD for: prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650/list_source INFO 22:19:54.654 (FedoraLdp) HEAD for: prod/3f/e5/49/8f/3fe5498f-3215-f6a2-6385-27528dec8848 INFO 22:19:54.667 (FedoraLdp) HEAD for: prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650 INFO 22:19:54.673 (FedoraLdp) GET resource 'prod/3f/e5/49/8f/3fe5498f-3215-f6a2-6385-27528dec8848' INFO 22:19:54.688 (FedoraLdp) GET resource 'prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650'

       

      The software we're using is called Fedora.  Naturally, I've asked this question in the Fedora community, but as it appears to be deep in the stack, at the modeshape layer, I'm hoping this forum might be able to shed some light on this for me.

       

      FWIW, I cannot reliably reproduce this error except in a single environment, which makes it seem environmental, but the software being used is deployed identically in the problem environment compared to a non-problem environment.  The only difference is load, which is substantial.  These errors started appearing when we started to hammer the system.

       

      The above error stems from an HTTP PUT, which adds a resource to the system, which modeshape handles.  If it is helpful, I get the same error when the same resource is later deleted from the system [2].

       

      INFO 13:16:59.148 (FedoraLdp) Delete resource 'prod/da/39/e4/3d/da39e43d-fd1a-5971-8f7b-3f36fabcc650' ERROR 13:17:00.592 (RepositoryChangeBus) Unexpected error while processing the event 'Save by 'bypassAdmin' at 2017-02-24T13:16:59.935-06:00 with user data = {org.modeshape.jcr.observation.userdata={"baseUrl":"https://aicdamstest08.artic.edu/fcrepo/rest/","userAgent":"python-requests/2.10.0"}} in repository with key '927fdb8' and workspace 'default'   Removed node '87a0a8c7505d648ca127a2-8687-45ce-a805-00a454c5b6d3' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650/{}members" from under 87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7   Removed node '87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650" from under 87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6   Added property {http://www.w3.org/ns/auth/acl#}accessTo_ref from node '87a0a8c7505d64a2864e43-cff8-4bf8-a5d4-f4782a2d82b8' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}2f/{}d9/{}72/{}c5/{}2fd972c5-f381-4838-9dae-569e11feba60 with values:{http://www.w3.org/ns/auth/acl#}accessTo_ref = [87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7]   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64a2864e43-cff8-4bf8-a5d4-f4782a2d82b8' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}2f/{}d9/{}72/{}c5/{}2fd972c5-f381-4838-9dae-569e11feba60 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:55.366-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Removed node '87a0a8c7505d6497621383-7887-40ea-963b-af4b0520902e' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650/{}list_source/{}#/{}g70259711318740" from under 87a0a8c7505d644f8fb26a-9915-467d-a954-00c62355bc98   Added property {http://www.w3.org/ns/auth/acl#}accessTo_ref from node '87a0a8c7505d64c719adc3-ed2b-40ff-9797-4cc54ba2004c' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}c2/{}aa/{}af/{}30/{}c2aaaf30-6310-4d1a-bfc2-48e141b05f9a with values:{http://www.w3.org/ns/auth/acl#}accessTo_ref = [87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7]   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64c719adc3-ed2b-40ff-9797-4cc54ba2004c' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}c2/{}aa/{}af/{}30/{}c2aaaf30-6310-4d1a-bfc2-48e141b05f9a from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:55.760-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Added property {http://www.w3.org/ns/auth/acl#}accessTo_ref from node '87a0a8c7505d646c09e144-0bbb-486b-9b0f-48541698e37e' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}23/{}a3/{}3f/{}cb/{}23a33fcb-ad75-4aea-ac89-a8e753d37292 with values:{http://www.w3.org/ns/auth/acl#}accessTo_ref = [87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7]   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d646c09e144-0bbb-486b-9b0f-48541698e37e' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d/{}23/{}a3/{}3f/{}cb/{}23a33fcb-ad75-4aea-ac89-a8e753d37292 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:55.611-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Removed node '87a0a8c7505d64cbd22919-5aef-4865-9a76-6442ee5bf515' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650/{}list_source" from under 87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051' at path /{}prod/{}f6/{}db/{}51/{}2a/{}f6db512a-25d3-6290-e0c9-29c7fea7e795 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-22T17:12:05.980-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Changed node '87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051' at "/{}prod/{}f6/{}db/{}51/{}2a/{}f6db512a-25d3-6290-e0c9-29c7fea7e795"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d642b0d7586-d71e-4605-ad5e-8fafbd27dee3' at path /{}prod/{}8k/{}71/{}nk/{}67/{}8k71nk67g from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:20:06.735-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Changed node '87a0a8c7505d642b0d7586-d71e-4605-ad5e-8fafbd27dee3' at "/{}prod/{}8k/{}71/{}nk/{}67/{}8k71nk67g"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d' at path /{}prod/{}58/{}f0/{}0e/{}ca/{}58f00eca-c398-02f0-f9bb-6b2b6105c0ef from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:57.930-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Changed node '87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d' at "/{}prod/{}58/{}f0/{}0e/{}ca/{}58f00eca-c398-02f0-f9bb-6b2b6105c0ef"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f' at path /{}prod/{}88/{}94/{}a0/{}f6/{}8894a0f6-ab34-3f23-60a0-353ea1ba4242 from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-23T15:04:32.009-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Changed node '87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f' at "/{}prod/{}88/{}94/{}a0/{}f6/{}8894a0f6-ab34-3f23-60a0-353ea1ba4242"   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592' at path /{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-17T22:19:56.395-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00   Changed node '87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592' at "/{}prod/{}d6/{}6b/{}e1/{}30/{}d66be130-c30d-45ba-9074-26ce2d47020d"   Removed node '87a0a8c7505d64c2fbcba9-d08a-47ce-8e9b-9c47da70a2a4' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650/{}members/{}efe6cb87-b735-4220-8309-c18215d94f8d" from under 87a0a8c7505d648ca127a2-8687-45ce-a805-00a454c5b6d3   Removed node '87a0a8c7505d644f8fb26a-9915-467d-a954-00c62355bc98' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650/{}list_source/{}#" from under 87a0a8c7505d64cbd22919-5aef-4865-9a76-6442ee5bf515   Added node '87a0a8c7505d6470ccf5f6-3edc-4db5-b389-317a687afbd7' at "/{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650" under '87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6'   Added property {http://www.jcp.org/jcr/1.0}createdBy to node '87a0a8c7505d6470ccf5f6-3edc-4db5-b389-317a687afbd7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}createdBy = bypassAdmin   Added property {http://www.jcp.org/jcr/1.0}primaryType to node '87a0a8c7505d6470ccf5f6-3edc-4db5-b389-317a687afbd7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}primaryType = {http://fedora.info/definitions/v4/repository#}Tombstone   Added property {http://www.jcp.org/jcr/1.0}created to node '87a0a8c7505d6470ccf5f6-3edc-4db5-b389-317a687afbd7' at path /{}prod/{}da/{}39/{}e4/{}3d/{}da39e43d-fd1a-5971-8f7b-3f36fabcc650 with values:{http://www.jcp.org/jcr/1.0}created = 2017-02-24T13:16:59.569-06:00   Changed property {http://fedora.info/definitions/v4/repository#}lastModified on node '87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb' at path /{}prod from:{http://fedora.info/definitions/v4/repository#}lastModified = 2017-02-24T19:16:57.930Z to:{http://fedora.info/definitions/v4/repository#}lastModified = 2017-02-24T19:16:59.569Z   Changed property {http://www.jcp.org/jcr/1.0}lastModified on node '87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb' at path /{}prod from:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:57.930-06:00 to:{http://www.jcp.org/jcr/1.0}lastModified = 2017-02-24T13:16:59.569-06:00 changed 17 nodes:   87a0a8c7505d64a7c914f1-4c55-48cb-9283-f3d0974713c6   87a0a8c7505d64c2fbcba9-d08a-47ce-8e9b-9c47da70a2a4   87a0a8c7505d6470ccf5f6-3edc-4db5-b389-317a687afbd7   87a0a8c7505d64fbb60574-7007-44e1-8a88-5f217e00335d   87a0a8c7505d64471df0cf-589d-430e-b516-cfb0fbf34fa7   87a0a8c7505d645b4fb77a-cd43-4c30-92c1-83b6469cf9eb   87a0a8c7505d64a2864e43-cff8-4bf8-a5d4-f4782a2d82b8   87a0a8c7505d642b0d7586-d71e-4605-ad5e-8fafbd27dee3   87a0a8c7505d6464b137ea-2538-4f85-9a7e-fd4bb633d25f   87a0a8c7505d64012368ef-82e4-4d7b-b439-65c77622b592   87a0a8c7505d64a85d5955-2937-44f1-b807-5b80eb5d2051   87a0a8c7505d6497621383-7887-40ea-963b-af4b0520902e   87a0a8c7505d64c719adc3-ed2b-40ff-9797-4cc54ba2004c   87a0a8c7505d644f8fb26a-9915-467d-a954-00c62355bc98   87a0a8c7505d64cbd22919-5aef-4865-9a76-6442ee5bf515   87a0a8c7505d646c09e144-0bbb-486b-9b0f-48541698e37e   87a0a8c7505d648ca127a2-8687-45ce-a805-00a454c5b6d3 ' with the sequence number '3531387' java.lang.NullPointerException: null

       

      Spot checks suggest these resources are not corrupt: there is no error when they are fetched; I can still write to the repository/path; they appear to be removed OK.  In short, although this manifests as an ERROR it does not seem to impair the repository, though I've not rigorously tested that last statement.

       

      I'd be interested in any feedback about what this error might mean and what ramifications, if any, there may be. I've not seen any, but I may not be looking in the right place.

       

      All the best,

      Kevin

       

      EDIT: I tried to enter the log info in-line, but the newline characters are being stripped resulting in the the entry being on a single line, which is hardly helpful.  Find links below to properly formatted entries.

       

      [1] fcrepo-log-modeshape-error · GitHub

      [2] fcrepo-log-modeshape-error · GitHub

        • 1. Re: errorProcessingEvent? "Unexpected error while processing the event"
          hchiorean

          from looking at the stacktrace (only relevant parts included):

           

          at org.fcrepo.kernel.modeshape.observer.DefaultFilter.test(DefaultFilter.java:52)
          at org.fcrepo.kernel.modeshape.observer.DefaultFilter.test(DefaultFilter.java:45)
          at com.google.common.collect.Iterators$6.computeNext(Iterators.java:617)
          at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:145)
          at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:140)
          at java.util.Iterator.forEachRemaining(Iterator.java:115)
          at java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1801)
          at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:481)
          at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:471)
          at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:708)
          at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
          at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:499)
          at org.fcrepo.kernel.modeshape.observer.eventmappings.AllNodeEventsOneEvent.apply(AllNodeEventsOneEvent.java:68)
          at org.fcrepo.kernel.modeshape.observer.eventmappings.AllNodeEventsOneEvent.apply(AllNodeEventsOneEvent.java:48)
          at org.fcrepo.kernel.modeshape.observer.SimpleObserver.onEvent(SimpleObserver.java:222)
          at org.modeshape.jcr.JcrObservationManager$JcrListenerAdapter.notify(JcrObservationManager.java:294)
          

           

          line (16) is the ModeShape JCR event listener adapter but everything upwards of that is non ModeShape code. In other words, the NPE is caused by some code inside the DefaultFilter class (which is not part of the ModeShape codebase).

           

          The semantics are that of a JCR event listener which receives a notification about some event and then fails with a NPE. The investigation into this problem should start from whoever owns the org.fcrepo.kernel.modeshape package