[Exist-open] Problem with triggers in eXist 1.4.0 - lots of " Node 1.14.7.5.2.2 could not be found.

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

I have been having trouble getting the trigger functionality to work in
eXist 1.4.0. I've tried this under Solaris 10 and Redhat Linux (x86_64)
using JDK 1.6.0_21

I added one of the sample triggers listed in the trigger documentation into
a collection.xconf:

<collection xmlns="http://exist-db.org/collection-config/1.0">
 <triggers>
  <trigger event="store,update,remove"
class="org.exist.collections.triggers.XQueryTrigger">
   <parameter name="query" value="util:log('debug', concat('Trigger
fired at ', current-dateTime()))"/>
  </trigger>
 </triggers>
</collection>

When I add a new document to this collection I see the following messages in
the exist.log file:

2010-09-02 16:12:22,442 [P1-8] DEBUG (NativeBroker.java
[getOrCreateCollection]:630) - Creating collection '/db/psdm/not/txc-not/201
0'...
2010-09-02 16:12:22,443 [P1-8] DEBUG (Collection.java [setupTriggers]:1402)
- Using store trigger 'org.exist.collections.triggers.XQueryTrigger'
2010-09-02 16:12:22,443 [P1-8] DEBUG (XQueryTrigger.java [prepare]:182) -
Preparing STOREXQuery trigger for document:
'/db/psdm/not/txc-not/2010/ps2k_txc-not_20100901'
2010-09-02 16:12:22,464 [P1-8] INFO  (CompressionModule.java [<init>]:60) -
Instantiating Compression module
2010-09-02 16:12:22,464 [P1-8] INFO  (CacheModule.java [<init>]:56) -
Instantiating Cache module
2010-09-02 16:12:22,487 [P1-8] DEBUG (XQuery.java [compile]:155) - Query
diagnostics:
util:log("debug", concat("Trigger fired at ", current-dateTime()))
2010-09-02 16:12:22,487 [P1-8] DEBUG (XQuery.java [compile]:161) -
Compilation took 23 ms
2010-09-02 16:12:22,488 [P1-8] DEBUG (LogFunction.java [eval]:145) - (Line:
1) Trigger fired at 2010-09-02T16:12:22.488-04:00
2010-09-02 16:12:22,489 [P1-8] DEBUG (XQuery.java [execute]:231) - Execution
took 1 ms
2010-09-02 16:12:22,489 [P1-8] DEBUG (HTTPUtils.java
[addLastModifiedHeader]:61) - mostRecentDocumentTime: 0
2010-09-02 16:12:22,489 [P1-8] DEBUG (XQueryTrigger.java [prepare]:258) -
Trigger fired for prepare
2010-09-02 16:12:22,489 [P1-8] DEBUG (Collection.java
[validateXMLResourceInternal]:1218) - Scanning document
/db/psdm/not/txc-not/2010/ps2k_txc-not_20100901
2010-09-02 16:12:22,490 [P1-8] DEBUG (GrammarPool.java
[retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (
http://www.w3.org/TR/REC-xml).
2010-09-02 16:12:22,490 [P1-8] DEBUG (GrammarPool.java
[retrieveInitialGrammarSet]:85) - Found 0 grammars.
2010-09-02 16:12:22,512 [P1-8] DEBUG (Collection.java
[storeXMLInternal]:1036) - storing document 10379 ...
2010-09-02 16:12:22,513 [P1-8] DEBUG (GrammarPool.java
[retrieveInitialGrammarSet]:81) - Retrieve initial grammarset (
http://www.w3.org/TR/REC-xml).
2010-09-02 16:12:22,513 [P1-8] DEBUG (GrammarPool.java
[retrieveInitialGrammarSet]:85) - Found 0 grammars.
2010-09-02 16:12:22,661 [P1-8] DEBUG (Collection.java
[storeXMLInternal]:1050) - document stored.
2010-09-02 16:12:22,662 [P1-8] DEBUG (XQueryTrigger.java [finish]:273) -
Finishing STORE XQuery trigger for document :
'/db/psdm/not/txc-not/2010/ps2k_txc-not_20100901'
2010-09-02 16:12:22,662 [P1-8] INFO  (CompressionModule.java [<init>]:60) -
Instantiating Compression module
2010-09-02 16:12:22,663 [P1-8] INFO  (CacheModule.java [<init>]:56) -
Instantiating Cache module
2010-09-02 16:12:22,664 [P1-8] DEBUG (XQuery.java [compile]:155) - Query
diagnostics:
util:log("debug", concat("Trigger fired at ", current-dateTime()))
2010-09-02 16:12:22,665 [P1-8] DEBUG (XQuery.java [compile]:161) -
Compilation took 2 ms
2010-09-02 16:12:22,687 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.7.5.2.2 could not be found. Giving up.
2010-09-02 16:12:22,687 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.7.5.2.2 not found
2010-09-02 16:12:22,688 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.7.5.3.2 could not be found. Giving up.
2010-09-02 16:12:22,688 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.7.5.3.2 not found
2010-09-02 16:12:22,689 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.7.5.4.2 could not be found. Giving up.
2010-09-02 16:12:22,689 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.7.5.4.2 not found
2010-09-02 16:12:22,689 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.7.5.5 could not be found. Giving up.
2010-09-02 16:12:22,690 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.7.5.5 not found
2010-09-02 16:12:22,690 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.7.6 could not be found. Giving up.
2010-09-02 16:12:22,690 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.7.6 not found
2010-09-02 16:12:22,691 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.9.4.2 could not be found. Giving up.
2010-09-02 16:12:22,692 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.9.4.2 not found
2010-09-02 16:12:22,692 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.9.5.2 could not be found. Giving up.
2010-09-02 16:12:22,692 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.9.5.2 not found
2010-09-02 16:12:22,693 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.9.6.2 could not be found. Giving up.
2010-09-02 16:12:22,693 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.9.6.2 not found
2010-09-02 16:12:22,693 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.9.7 could not be found. Giving up.
2010-09-02 16:12:22,694 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.9.7 not found
2010-09-02 16:12:22,695 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.13.2.2.2 could not be found. Giving up.
2010-09-02 16:12:22,695 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.13.2.2.2 not found
2010-09-02 16:12:22,696 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.13.2.3.2 could not be found. Giving up.
2010-09-02 16:12:22,696 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.13.2.3.2 not found
2010-09-02 16:12:22,697 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.13.2.4.10.4 could not be found. Giving up.
2010-09-02 16:12:22,697 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.13.2.4.10.4 not found
2010-09-02 16:12:22,699 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.13.2.4.11.14 could not be found. Giving up.
2010-09-02 16:12:22,700 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.13.13.2.4.11.14 not found
2010-09-02 16:12:22,702 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.14.13.13.2.4.12.14 could not be found. Giving up.
...
these messages continue for several hundred lines in the log file, after
which I see:

2010-09-02 16:12:28,426 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.14.14 not found
2010-09-02 16:12:28,430 [P1-8] DEBUG (DOMFile.java [findValue]:1359) - Node
1.15 could not be found. Giving up.
2010-09-02 16:12:28,430 [P1-8] DEBUG (NativeBroker.java [start]:3070) - Node
1.15 not found
2010-09-02 16:12:28,430 [P1-8] DEBUG (LogFunction.java [eval]:145) - (Line:
1) Trigger fired at 2010-09-02T16:12:28.43-04:00
2010-09-02 16:12:28,430 [P1-8] DEBUG (XQuery.java [execute]:231) - Execution
took 0 ms
2010-09-02 16:12:28,430 [P1-8] DEBUG (HTTPUtils.java
[addLastModifiedHeader]:61) - mostRecentDocumentTime: 0
2010-09-02 16:12:28,431 [P1-8] DEBUG (XQueryTrigger.java [finish]:357) -
Trigger fired for finish

Has anyone else had this problem? I've searched the list archives and nobody
seems to have reported it.

Dan Speck

[Exist-open] Problem with triggers in eXist 1.4.0 - lots of " Node 1.14.7.5.2.2 could not be found.

eXist-db is a feature rich Open Source native XML database

[Exist-open] Problem with triggers in eXist 1.4.0 - lots of " Node 1.14.7.5.2.2 could not be found. Giving up." messages in log