From: Raul D. <r.d...@dm...> - 2007-08-16 17:27:55
|
>> Still not sure what general comparison triggers that logging though. To be clear, since the lookup over the two nodes, shift and result uses the same values, I changed them to see which one is triggering the lookup. Here are the new XQueries: 1) Inline: xquery version "1.0"; declare namespace tools="java:test.XQuery"; let $resultdoc := document{ <results> { let $results := collection("/db/results/")/pricing/results/result[@type eq 'value' and @name eq 'mtm'] for $result in $results let $pricing :=$result/ancestor::node()/ancestor::node() return( <result>{string-join(($pricing/@id,$pricing/input/user,1,1, 0,tools:normalise(tools:round($result,9),$pricing/input/requests/request[@type eq 'value' and @name eq 'theta']/number_of_days)),",")}</result> ) } </results> } for $line in $resultdoc/results/result return $line/text() logs: 2007-08-16 18:08:10,067 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:407) - found an index of type: xs:string 2007-08-16 18:08:10,067 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:452) - Checking if range index can be used for key: value 2007-08-16 18:08:10,067 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:457) - Using range index for key: value 2007-08-16 18:08:10,208 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:407) - found an index of type: xs:string 2007-08-16 18:08:10,208 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:452) - Checking if range index can be used for key: mtm 2007-08-16 18:08:10,224 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:457) - Using range index for key: mtm 2007-08-16 18:08:13,083 DEBUG [main] storage.NativeBroker (NativeBroker.java:660) - Creating collection '/db/system/temp'... 2007-08-16 18:08:13,099 DEBUG [main] collections.CollectionConfigurationManager (CollectionConfigurationManager.java:165) - Reading collection configuration for '/db/system/temp' from index configuration 2007-08-16 18:08:13,302 DEBUG [main] storage.CacheManager (CacheManager.java:180) - Growing cache elements.dbx (a org.exist.storage.cache.LRUCache) from 64 to 80 2007-08-16 18:08:13,302 DEBUG [main] xquery.XQueryContext (XQueryContext.java:1634) - Stored: 3462: /db/system/temp/27fb3d18c212ee464ce5128e30604a63.xml 2007-08-16 18:08:13,364 DEBUG [main] util.HTTPUtils (HTTPUtils.java:61) - mostRecentDocumentTime: 1187284093083 2007-08-16 18:08:13,380 DEBUG [main] xmldb.LocalXPathQueryService (LocalXPathQueryService.java:374) - query took 3875 ms. 2) looking for number_of_days before doing the string_join(): xquery version "1.0"; declare namespace tools="java:test.XQuery"; let $resultdoc := document{ <results> { let $results := collection("/db/results/")/pricing/results/result[@type eq 'value' and @name eq 'mtm'] for $result in $results let $pricing :=$result/ancestor::node()/ancestor::node() let $nbOfDays := $pricing/input/requests/request[@type eq 'value' and @name eq 'theta']/number_of_days return( <result>{string-join(($pricing/@id,$pricing/input/user,1,1, 0,tools:normalise(tools:round($result,9),$nbOfDays)),",")}</result> ) } </results> } for $line in $resultdoc/results/result return $line/text() logs: 2007-08-16 18:08:42,367 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:407) - found an index of type: xs:string 2007-08-16 18:08:42,367 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:452) - Checking if range index can be used for key: value 2007-08-16 18:08:42,367 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:457) - Using range index for key: value 2007-08-16 18:08:42,523 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:407) - found an index of type: xs:string 2007-08-16 18:08:42,523 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:452) - Checking if range index can be used for key: mtm 2007-08-16 18:08:42,523 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:457) - Using range index for key: mtm 2007-08-16 18:08:42,695 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: value 2007-08-16 18:08:42,711 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: theta 2007-08-16 18:08:42,789 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: value 2007-08-16 18:08:42,805 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: theta 2007-08-16 18:08:42,851 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: value 2007-08-16 18:08:42,867 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: theta 2007-08-16 18:08:43,055 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: value 2007-08-16 18:08:43,070 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: theta 2007-08-16 18:08:43,117 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: value 2007-08-16 18:08:43,133 TRACE [main] xquery.GeneralComparison (GeneralComparison.java:518) - No suitable index found for key: theta <<<thousands of times>>> 2007-08-16 18:12:42,373 DEBUG [main] storage.NativeBroker (NativeBroker.java:660) - Creating collection '/db/system/temp'... 2007-08-16 18:12:42,373 DEBUG [main] collections.CollectionConfigurationManager (CollectionConfigurationManager.java:165) - Reading collection configuration for '/db/system/temp' from index configuration 2007-08-16 18:12:42,560 DEBUG [main] xquery.XQueryContext (XQueryContext.java:1634) - Stored: 3462: /db/system/temp/953d7223dab9fcb1c1959128e307f6fe.xml 2007-08-16 18:12:42,654 DEBUG [main] util.HTTPUtils (HTTPUtils.java:61) - mostRecentDocumentTime: 1187284362373 2007-08-16 18:12:42,670 INFO [main] storage.NativeBroker (NativeBroker.java:2756) - Memory: 253440K total; 1013632K max; 129011K free 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - dom.dbx INDEX Buffers occupation : 50% (32 out of 64) Cache efficiency : 100% 2007-08-16 18:12:42,670 INFO [main] dom.DOMFile (DOMFile.java:1235) - dom.dbx DATA Buffers occupation : 100% (255 out of 256) Cache efficiency : 95% 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - collections.dbx INDEX Buffers occupation : 33% (21 out of 64) Cache efficiency : 80% 2007-08-16 18:12:42,670 INFO [main] index.BFile (BFile.java:434) - collections.dbx DATA Buffers occupation : 98% (63 out of 64) Cache efficiency : 98% 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - elements.dbx INDEX Buffers occupation : 2% (1 out of 64) Cache efficiency : 100% 2007-08-16 18:12:42,670 INFO [main] index.BFile (BFile.java:434) - elements.dbx DATA Buffers occupation : 98% (63 out of 64) Cache efficiency : 0% 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - values.dbx INDEX Buffers occupation : 2% (1 out of 64) Cache efficiency : 67% 2007-08-16 18:12:42,670 INFO [main] index.BFile (BFile.java:434) - values.dbx DATA Buffers occupation : 91% (58 out of 64) Cache efficiency : 0% 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - values-by-qname.dbx INDEX Buffers occupation : 2% (1 out of 64) Cache efficiency : 0% 2007-08-16 18:12:42,670 INFO [main] index.BFile (BFile.java:434) - values-by-qname.dbx DATA Buffers occupation : 0% (0 out of 64) Cache efficiency : N/A 2007-08-16 18:12:42,670 INFO [main] btree.BTree (BTree.java:2046) - words.dbx INDEX Buffers occupation : 5% (3 out of 64) Cache efficiency : 0% 2007-08-16 18:12:42,670 INFO [main] index.BFile (BFile.java:434) - words.dbx DATA Buffers occupation : 0% (0 out of 64) Cache efficiency : N/A 2007-08-16 18:12:42,670 DEBUG [main] journal.Journal (Journal.java:298) - Checkpoint reached 2007-08-16 18:12:42,670 DEBUG [main] storage.NotificationService (NotificationService.java:62) - Registered UpdateListeners: 2007-08-16 18:12:42,670 DEBUG [main] xmldb.LocalXPathQueryService (LocalXPathQueryService.java:374) - query took 240850 ms. >> Looks correct. The index is used. But since if is used in an iteration, >> it is looked-up on every one. That's what should be avoided either by >> the user (that's my point), either by the code (for which we can indeed >> suspect something is going wrong). The lookup is being triggered for the nb_of_days node, not for the result node. It seems in the first case the eXist code is avoiding the lookup and not in the second one... Again, when I run 1) on eXist 1.1.2dev I get the execution mode error, whereas 2) produces the same result as in eXist 1.1.1.. so this might be a hint to the issue... It looks like in 1) it finds that the XML fragment is already loaded, and in 2) it believes it's not (should have to run in debug mode and check the contents of the objects to prove it). >> HOWEVER >> >> $pricing/input/requests/request[@type='value' and @name='mtm']/shift >> >> has no dependency on $result right ? so... why not define a $shift >> variable *outside* of the iteration over each $result ? That would save >> as many index lookups. I have a collection with 4000 documents. Each document has one pricing root node, one pricing/results node, and several pricing/results/result nodes, one for each @type/@name combination. each pricing has one pricing/input/requests/request/shift node for each combination of @type and @name. This shift is different for each pricing and for each @type/@name combination. I'm not iterating over each result in a given pricing, but over all the results of a given @type/@name combination across all the pricing documents in the collection. Therefore, each shift (or other pricing parameters) need to be retrieved for each result of each pricing. Now, this said, I think the shift (or parameter) lookup behaviour should be consistent between 1) and 2) since I'm iterating over the same nodes in the same way. The only difference is that in 1) the node is retrieved inside the return for the loop, and in 2) it's retrieved before the return for the loop. I tried to retrieve other values from $pricing and $result (even doing all the lookups and operations) before the return statement, and still get those thousands of lookups... Thanks again for your time! Regards, Raul >> Hi, >> >> Raul Davidovich a écrit : >> >>> for $pricing in collection("/db/results/")/pricing return( for >>> $result in $pricing/results/result[@type='value' and @name='mtm'] >>> return( string-join(($pricing/@id, $pricing/input/user, 1, 0, "", >>> tools:normalise(tools:round($result,9),$pricing/input/requests/request[@type='value' >>> and @name='mtm']/shift)),",") ) ) >>> >>> >>> If my understanding is right, for each "pricing" element in the >>> collection /db/results, that node will be entirely bound (including >>> all of it's children) to the $pricing variable. >> >> Exactly. >> >>> Therefore, if I then do $pricing/results/result[@type='value' and >>> @name='mtm'], it should retrieve it from the XML fragment it already >>> got from the DB and that should be in memory, right? >> >> Exactly. >> >>> no need to query again the DB for that? >> >> No. It would be counter-productive. >> >>> Or is there some kind of "lazy loading" where only the "pricing" node >>> is retrieved from the DB and not it's children, >> >> Impossible : a node which is "retrieved" is retrieved together with its >> children (and attributes if relevant). That's how XPath works. >> >> BUT >> >> eXist avoids to "retrieve" any value until it is actually needed. >> Instead, it tries to work with node *references*. That allows to work >> efficiently on sequences containing millions of nodes. >> >>> so that when they are referenced, there is a new query to the DB to >>> retrieve it? >>> >>> This last thing is what seems to be happening. .. I'm getting >>> thousands of log lines saying: >>> >>> 2007-08-16 15:53:42,758 TRACE [main] xquery.GeneralComparison >>> (GeneralComparison.java:452) - Checking if range index can be used >>> for key: value 2007-08-16 15:53:42,758 TRACE [main] >>> xquery.GeneralComparison (GeneralComparison.java:457) - Using range >>> index for key: value 2007-08-16 15:53:42,774 TRACE [main] >>> xquery.GeneralComparison (GeneralComparison.java:407) - found an >>> index of type: xs:string 2007-08-16 15:53:42,774 TRACE [main] >>> xquery.GeneralComparison (GeneralComparison.java:452) - Checking if >>> range index can be used for key: mtm 2007-08-16 15:53:42,774 TRACE >>> [main] xquery.GeneralComparison (GeneralComparison.java:457) - Using >>> range index for key: mtm >> >> Looks correct. The index is used. But since if is used in an iteration, >> it is looked-up on every one. That's what should be avoided either by >> the user (that's my point), either by the code (for which we can indeed >> suspect something is going wrong). >> >> Still not sure what general comparison triggers that logging though. >> >> HOWEVER >> >> $pricing/input/requests/request[@type='value' and @name='mtm']/shift >> >> has no dependency on $result right ? so... why not define a $shift >> variable *outside* of the iteration over each $result ? That would save >> as many index lookups. >> >>> I then tried the "no index" hint in the latest SVN code: >> >> Totally experimental and probably not (yet) usable by every kind of >> index. That may explain... >> >> [snip : tail quotation] >> >> Cheers, >> >> p.b. >> |