profiling function execution order

On Tue, Aug 28, 2012 at 4:33 PM, Seenivasan Gunabalan <seenivasan.gunabalan at dedalus.eu> wrote: > Dear all, > We have an question regarding the prof:current-ns() / > prof:current-ms() in basex7.4 beta. > our need is to calculate the execution time of the calling function. > consider the example below, > > let $o1 := prof:current-ns() > let $resp := http:send-request(<http:request method="GET" > href="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" > status-only = "false" > username = "admin" > password = "admin" > send-authorization="true"> > </http:request>) > let $o2 := prof:current-ns() > let $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd")) > let $o3 := prof:current-ns() > > return ($o2 - $o1, $o3 - $o2, $v) > > > After spending some time in trying the understand why the timings were not > coherent ( validation time is almost 0 when compared to the total time), we > noticed that the query plan was modified in the following way, > > Query: let $o1 := prof:current-ns() let $resp := > http:send-request(<http:request method="GET" > href="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" > status-only = "false" username = "admin" password = "admin" > send-authorization="true"> </http:request>) let $o2 := prof:current-ns() let > $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd")) let $o3 := > prof:current-ns() return ($o2 - $o1, $o3 - $o2, $v) > Compiling: > - moving for/let clauses > Result: let $o1 := prof:current-ns() let $resp := http:send-request(element > { Q{http://expath.org/ns/http-client}request } { attribute { method } { > "GET" }, attribute { href } { > "http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" > }, attribute { status-only } { "false" }, attribute { username } { "admin" > }, attribute { password } { "admin" }, attribute { send-authorization } { > "true" } }) let $v := validate:xsd(($resp)[2], > "../http/hdatatest/xsd/atom.xsd") let $o2 := prof:current-ns() let $o3 := > prof:current-ns() return ($o2 - $o1, $o3 - $o2, $v) > Timing: > - Parsing: 0.56 ms > - Compiling: 0.28 ms > - Evaluating: 3929.59 ms > - Printing: 0.04 ms > - Total Time: 3930.5 ms > Result: > - Hit(s): 2 Items > - Updated: 0 Items > - Printed: 15 Bytes > Query plan: > <QueryPlan> > <FLWR> > <Let var="$o1"> > <FNProf name="current-ns()"/> > </Let> > <Let var="$resp"> > <FNHttp name="send-request(request[,href,[bodies]])"> > <CElem> > <QNm value="http:request" type="xs:QName"/> > <CAttr> > <QNm value="method" type="xs:QName"/> > <Str value="GET" type="xs:string"/> > </CAttr> > <CAttr> > <QNm value="href" type="xs:QName"/> > <Str > value="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" > type="xs:string"/> > </CAttr> > <CAttr> > <QNm value="status-only" type="xs:QName"/> > <Str value="false" type="xs:string"/> > </CAttr> > <CAttr> > <QNm value="username" type="xs:QName"/> > <Str value="admin" type="xs:string"/> > </CAttr> > <CAttr> > <QNm value="password" type="xs:QName"/> > <Str value="admin" type="xs:string"/> > </CAttr> > <CAttr> > <QNm value="send-authorization" type="xs:QName"/> > <Str value="true" type="xs:string"/> > </CAttr> > </CElem> > </FNHttp> > </Let> > <Let var="$v"> > <FNValidate name="xsd(input[,schema])"> > <IterPosFilter> > <VarRef> > <Var name="$resp" id="1"/> > </VarRef> > <Pos min="2" max="2"/> > </IterPosFilter> > <Str value="../http/hdatatest/xsd/atom.xsd" type="xs:string"/> > </FNValidate> > </Let> > <Let var="$o2"> > <FNProf name="current-ns()"/> > </Let> > <Let var="$o3"> > <FNProf name="current-ns()"/> > </Let> > <Return> > <List> > <Arith op="-"> > <VarRef> > <Var name="$o2" id="2"/> > </VarRef> > <VarRef> > <Var name="$o1" id="0"/> > </VarRef> > </Arith> > <Arith op="-"> > <VarRef> > <Var name="$o3" id="4"/> > </VarRef> > <VarRef> > <Var name="$o2" id="2"/> > </VarRef> > </Arith> > <VarRef> > <Var name="$v" id="3"/> > </VarRef> > </List> > </Return> > </FLWR> > </QueryPlan> > > > and then after modifying the validation line into the following, we noticed > that the plan was not modified and the profile timings are as expected. > > let $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd"),$o2) > > Is it possible to skip the profiling functions from query optimization > process in order to avoid those kind of issues?. > > Thanks and kind regards, > > Seenivasan & Marco > > _______________________________________________ > BaseX-Talk mailing list > BaseX-Talk at mailman.uni-konstanz.de > https://mailman.uni-konstanz.de/mailman/listinfo/basex-talk

On Tue, Aug 28, 2012 at 8:05 PM, Christian Grün <christian.gruen at gmail.com> wrote: > Hi Seenivasan, hi Marco, > > thanks for your thorough analysis. I agree that the query rewriting > comes somewhat unexpected in your query, and wouldn’t even improve > performance for „deterministic” expressions in the let clause. > > I’ll have a look at that soon, and keep you updated, > Christian > ___________________________ > > On Tue, Aug 28, 2012 at 4:33 PM, Seenivasan Gunabalan > <seenivasan.gunabalan at dedalus.eu> wrote: >> Dear all, >> We have an question regarding the prof:current-ns() / >> prof:current-ms() in basex7.4 beta. >> our need is to calculate the execution time of the calling function. >> consider the example below, >> >> let $o1 := prof:current-ns() >> let $resp := http:send-request(<http:request method="GET" >> href="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" >> status-only = "false" >> username = "admin" >> password = "admin" >> send-authorization="true"> >> </http:request>) >> let $o2 := prof:current-ns() >> let $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd")) >> let $o3 := prof:current-ns() >> >> return ($o2 - $o1, $o3 - $o2, $v) >> >> >> After spending some time in trying the understand why the timings were not >> coherent ( validation time is almost 0 when compared to the total time), we >> noticed that the query plan was modified in the following way, >> >> Query: let $o1 := prof:current-ns() let $resp := >> http:send-request(<http:request method="GET" >> href="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" >> status-only = "false" username = "admin" password = "admin" >> send-authorization="true"> </http:request>) let $o2 := prof:current-ns() let >> $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd")) let $o3 := >> prof:current-ns() return ($o2 - $o1, $o3 - $o2, $v) >> Compiling: >> - moving for/let clauses >> Result: let $o1 := prof:current-ns() let $resp := http:send-request(element >> { Q{http://expath.org/ns/http-client}request } { attribute { method } { >> "GET" }, attribute { href } { >> "http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" >> }, attribute { status-only } { "false" }, attribute { username } { "admin" >> }, attribute { password } { "admin" }, attribute { send-authorization } { >> "true" } }) let $v := validate:xsd(($resp)[2], >> "../http/hdatatest/xsd/atom.xsd") let $o2 := prof:current-ns() let $o3 := >> prof:current-ns() return ($o2 - $o1, $o3 - $o2, $v) >> Timing: >> - Parsing: 0.56 ms >> - Compiling: 0.28 ms >> - Evaluating: 3929.59 ms >> - Printing: 0.04 ms >> - Total Time: 3930.5 ms >> Result: >> - Hit(s): 2 Items >> - Updated: 0 Items >> - Printed: 15 Bytes >> Query plan: >> <QueryPlan> >> <FLWR> >> <Let var="$o1"> >> <FNProf name="current-ns()"/> >> </Let> >> <Let var="$resp"> >> <FNHttp name="send-request(request[,href,[bodies]])"> >> <CElem> >> <QNm value="http:request" type="xs:QName"/> >> <CAttr> >> <QNm value="method" type="xs:QName"/> >> <Str value="GET" type="xs:string"/> >> </CAttr> >> <CAttr> >> <QNm value="href" type="xs:QName"/> >> <Str >> value="http://starling.us/cgi-bin/gus_atom_xsl.pl?atom=starling_us_atom.xml!sort_order=Title" >> type="xs:string"/> >> </CAttr> >> <CAttr> >> <QNm value="status-only" type="xs:QName"/> >> <Str value="false" type="xs:string"/> >> </CAttr> >> <CAttr> >> <QNm value="username" type="xs:QName"/> >> <Str value="admin" type="xs:string"/> >> </CAttr> >> <CAttr> >> <QNm value="password" type="xs:QName"/> >> <Str value="admin" type="xs:string"/> >> </CAttr> >> <CAttr> >> <QNm value="send-authorization" type="xs:QName"/> >> <Str value="true" type="xs:string"/> >> </CAttr> >> </CElem> >> </FNHttp> >> </Let> >> <Let var="$v"> >> <FNValidate name="xsd(input[,schema])"> >> <IterPosFilter> >> <VarRef> >> <Var name="$resp" id="1"/> >> </VarRef> >> <Pos min="2" max="2"/> >> </IterPosFilter> >> <Str value="../http/hdatatest/xsd/atom.xsd" type="xs:string"/> >> </FNValidate> >> </Let> >> <Let var="$o2"> >> <FNProf name="current-ns()"/> >> </Let> >> <Let var="$o3"> >> <FNProf name="current-ns()"/> >> </Let> >> <Return> >> <List> >> <Arith op="-"> >> <VarRef> >> <Var name="$o2" id="2"/> >> </VarRef> >> <VarRef> >> <Var name="$o1" id="0"/> >> </VarRef> >> </Arith> >> <Arith op="-"> >> <VarRef> >> <Var name="$o3" id="4"/> >> </VarRef> >> <VarRef> >> <Var name="$o2" id="2"/> >> </VarRef> >> </Arith> >> <VarRef> >> <Var name="$v" id="3"/> >> </VarRef> >> </List> >> </Return> >> </FLWR> >> </QueryPlan> >> >> >> and then after modifying the validation line into the following, we noticed >> that the plan was not modified and the profile timings are as expected. >> >> let $v := (validate:xsd($resp[2],"../http/hdatatest/xsd/atom.xsd"),$o2) >> >> Is it possible to skip the profiling functions from query optimization >> process in order to avoid those kind of issues?. >> >> Thanks and kind regards, >> >> Seenivasan & Marco >> >> _______________________________________________ >> BaseX-Talk mailing list >> BaseX-Talk at mailman.uni-konstanz.de >> https://mailman.uni-konstanz.de/mailman/listinfo/basex-talk

> plz find the sample code below. the particular URI will create a simple new > default xml under 'example' database. This was working fine in the previous > versions, but with the latest release(BaseX74-20120829.045851.zip), its just > hanging and never producing any response. Is there anywhere I need to do > configuration?