Hi Rose,
As you are runing v6 the profile function will not work it requires v7+ ...
The following shows simpler output with the compilation time being stated at
the end:
SQL> profile ('sparql select count(*) where {?s ?p ?o}');
result
LONG VARCHAR
_______________________________________________________________________________
287536
{
time 0.11% fanout 1 input 1 rows
time 0.08% fanout 1 input 1 rows
{ fork
time 1e+02% fanout 0 input 1 rows
RDF_QUAD 2.9e+05 rows()
After code:
0: sum callret-0 1 set no set_ctr
5: BReturn 0
}
time 0.046% fanout 0 input 1 rows
Select (callret-0)
}
4 msec 77% cpu, 1 rnd 287210 seq 0% same seg 0%
same pg
Compilation: 1 msec 0 reads 0% read 0 messages 0% clw
4 Rows. -- 132 msec.
SQL>
So compilation is 1ms and execution is 132msec
Best Regards
Hugh Williams
Professional Services
OpenLink Software, Inc. // http://www.openlinksw.com/
Weblog -- http://www.openlinksw.com/blogs/
LinkedIn -- http://www.linkedin.com/company/openlink-software/
Twitter -- http://twitter.com/OpenLink
Google+ -- http://plus.google.com/100570109519069333827/
Facebook -- http://www.facebook.com/OpenLinkSoftware
Universal Data Access, Integration, and Management Technology Providers
On 25 Nov 2013, at 11:19, Rose Beck <rosebeck...@gmail.com> wrote:
> Dear Hugh,
>
> Thanks a lot for the help.
> I am using virtuoso version: Version 6.1.8-dev.3127-pthreads as of Aug 10 2013
> Also I am unable to find the compilation and query execution time from the
> example result set given below. Can you please help me a bit with this.
> {
> -- In the below excerpt some lines are omitted. Comments are inline.
>
>
> time 1.3e-06% fanout 1 1 rows in
>
> s# 98 cluster outer seq start, set no <V $40 set_ctr in>
> save ctx:()
>
> -- the section inside the fork is executed to the end
> -- before the section after the fork is started.
> s# 161 Fork 42
> {
> wait time 0.00012% of exec real time, fanout 0
>
> -- The below introduces the 2 stage DFG which does most of the work.
> s# 108 { Cluster location fragment 51 0 unordered
> Params: ()
> Output: ()
>
> -- First partitioning step. Each of the 32 slices gets the
> -- identical plan to execute, this is a flood for all is this
> -- first step does not specify a partitioning key value.
>
> time 8e-05% fanout 0 0 rows in
> s# 115 Stage 1: Params: (<V $112 set_ctr in>)
>
> -- This is the initial table scan. The operator is executed
> -- 32 times, once for each slice of data.
>
> time 0.33% fanout 3.1e+06 32 rows in
> s# 121 from DB.DBA.ct_c by ct_c 1.7e+08 rows
> Key ct_c ASC (<V $28 a.k2 in>)
> [copies params]
> vector param casts: <V $40 set_ctr in>-> <V $112 set_ctr in>
>
> -- This is the second partitioning step, each of the rows of
> -- output of the previous is sent to the slice corresponding to K2.
>
> time 31% fanout 0.9 2e+08 rows in
> s# 131 Stage 2: Params: (<v $134 q_a.k2 S136 in>, <V $138 set_ctr in>)
>
> -- This is the 2nd index lookup, by a.k2 = b.k1 There are two
> -- parameters given in the vector param cast section, the first
> -- is a.k2 and the second is the set number. This is constant
> -- since the query is run on a single row of input but if the
> -- query were run on multiple rows of input this would specify
> -- which row of input the a.k2 comes from so that this would be
> -- aggregated in the right place. Many aggregates can be produced
> -- in a single invocation with multiple rows of input.
>
> time 68% fanout 0 2e+08 rows in
> s# 144 from DB.DBA.ct_c by ct_c unq 1 rows
> Key ct_c ASC ()
> inlined k1 = <v $134 q_a.k2 S136 in>
> vector param casts: <V $28 a.k2 in>-> <v $134 q_a.k2 S136 in>, <r $112
> set_ctr via S121>-> <V $138 set_ctr in>
>
>
> -- This is the aggregation.
>
> After code:
> 0: sum <V $43 count i> 1 set no <r $138 set_ctr via S144>
> 5: BReturn 0
>
> }
> }
>
> -- The below returns the aggregate to the client. The combining of
> -- aggregates from different slices is implicit in the for operator
> -- whenever this ends with a cluster location fragment.
>
> time 5.4e-07% fanout 0 1 rows in
> s# 164 Select (<V $43 count i>)
> set no: <V $40 set_ctr in>
> }
>
>
>
> On Mon, Nov 25, 2013 at 4:42 PM, Rose Beck <rosebeck...@gmail.com> wrote:
> Dear Hugh,
>
> Thanks a lot for the help. I tried to profile using profile but I am getting
> the following errors:
> SQL> profile('sparql select ?a?b?c where{?a ?b ?c}');
>
> *** Error 42001: [Virtuoso Driver][Virtuoso Server]SR185: Undefined procedure
> DB.DBA.profile.
> at line 9 of Top-Level:
> profile('sparql select ?a?b?c where{?a ?b ?c}')
> SQL> sparql profile('select ?a?b?c where{?a ?b ?c}');
>
> *** Error 37000: [Virtuoso Driver][Virtuoso Server]SQ074: Line 1: SP030:
> SPARQL compiler, line 1: syntax error at 'profile' before '('
> at line 10 of Top-Level:
> sparql profile('select ?a?b?c where{?a ?b ?c}')
>
>
>
> On Mon, Nov 25, 2013 at 4:35 PM, Hugh Williams <hwilli...@openlinksw.com>
> wrote:
> Hi Rose,
>
> With Virtuoso 7 you can obtain the compilation (query plan) and query
> execution time of a query using the "profile" function as detailed at:
>
>
> http://docs.openlinksw.com/virtuoso/databaseadmsrv.html#readingqueryprofile
>
> You can also enable general query logging and profiling using the
> "prof_enable" function as detailed at:
>
> http://docs.openlinksw.com/virtuoso/databaseadmsrv.html#querylogging
>
>
> Best Regards
> Hugh Williams
> Professional Services
> OpenLink Software, Inc. // http://www.openlinksw.com/
> Weblog -- http://www.openlinksw.com/blogs/
> LinkedIn -- http://www.linkedin.com/company/openlink-software/
> Twitter -- http://twitter.com/OpenLink
> Google+ -- http://plus.google.com/100570109519069333827/
> Facebook -- http://www.facebook.com/OpenLinkSoftware
> Universal Data Access, Integration, and Management Technology Providers
>
> On 25 Nov 2013, at 09:15, Rose Beck <rosebeck...@gmail.com> wrote:
>
>> After executing SPARQL queries in virtuoso using:
>> 1. ./isql 1111 dba dba
>> 2. And then firing the SPARQL query
>>
>> After this virtuoso returns the query execution time. So does the returned
>> time include the plan generation time. If yes, is it possible to find:
>> (plan generation time) and (time to retrieve the results after the plan has
>> already been generated by Virtuoso)?
>>
>> I need to know these query times as I am benchmarking Virtuoso against
>> postgreSQL. With postgresql I am able to separately retrieve the query
>> execution time after the plan has been generated by postgresql using
>> \timing. It would be great if Virtuoso could also give me the time it takes
>> to retrieve the results after the plan has been generated separately as
>> that would help me take a one to one comparison.
>>
>> I'll be really grateful to you for the guidance.
>> ------------------------------------------------------------------------------
>> Shape the Mobile Experience: Free Subscription
>> Software experts and developers: Be at the forefront of tech innovation.
>> Intel(R) Software Adrenaline delivers strategic insight and game-changing
>> conversations that shape the rapidly evolving mobile landscape. Sign up now.
>> http://pubads.g.doubleclick.net/gampad/clk?id=63431311&iu=/4140/ostg.clktrk_______________________________________________
>> Virtuoso-users mailing list
>> Virtuoso-users@lists.sourceforge.net
>> https://lists.sourceforge.net/lists/listinfo/virtuoso-users
>
>
>
------------------------------------------------------------------------------
Shape the Mobile Experience: Free Subscription
Software experts and developers: Be at the forefront of tech innovation.
Intel(R) Software Adrenaline delivers strategic insight and game-changing
conversations that shape the rapidly evolving mobile landscape. Sign up now.
http://pubads.g.doubleclick.net/gampad/clk?id=63431311&iu=/4140/ostg.clktrk
_______________________________________________
Virtuoso-users mailing list
Virtuoso-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/virtuoso-users
