Issue Details (XML | Word | Printable)

Key: CORE-4448
Type: Improvement Improvement
Status: Open Open
Priority: Major Major
Assignee: Vlad Khorsun
Reporter: Pavel Zotov
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
Firebird Core

Add statistics (and not only elapsed time) in output when use execute statements inside parent query (EB or SP)

Created: 02/Jun/14 05:54 PM   Updated: 06/Jun/14 06:38 AM
Component/s: TRACEMGR
Affects Version/s: 3.0 Alpha 2
Fix Version/s: None


 Description  « Hide
DDL:

recreate table t(s varchar(36) unique); commit;
insert into t select uuid_to_char( gen_uuid() )
from rdb$types,rdb$types,(select 1 i from rdb$types rows 30)
rows 500000;
commit;

Query: select count(*) from (select * from t order by s); - takes about 1500 ms on my machine.

If I run trace with the following config options:
  time_threshold = 2000
  log_statement_finish = true
  print_plan = true
  print_perf = true

- then trace will NOT show statistics for this query (if it run separately) and it's OK.

If then I run: select count(*) from (select t.* from t,(select 1 i from rdb$types rows 7) );
- then statistics will be like this:
PLAN JOIN (RDB$TYPES NATURAL, T NATURAL)
1 records fetched
   2016 ms, 7035203 fetch(es)

Table Natural Index Update Insert Delet
********************************************************************************
RDB$TYPES 7
T 3500000

And if I run the following EB:
set term ^;
execute block as
  declare n int;
  declare s varchar(80) = 'select count(*) from (select * from t order by s)';
begin
  select count(*) from (select t.* from t,(select 1 i from rdb$types rows 7) ) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
  execute statement (s) into n;
end
^ set term ;^

- I will get the following data:
PLAN JOIN (RDB$TYPES NATURAL, T NATURAL)
0 records fetched
  11937 ms, 7035203 fetch(es)

Table Natural Index Update Insert Delete Backout Purge Expunge
***************************************************************************************************************
RDB$TYPES 7
T 3500000

So, we can see the increased total time but the SAME statistics (fetches in this sample). This occured because each ES have 'too small' time to be displayed in the trace due to time_threshold parameter of trace config. But all such ES can significantly increase total (overall) time.
It is impossible now to detect such ES unless set trace time_threshold to small value but it will lead to much more trace output and will degrade performance because of IO.

Is it possible to include *statistics* (not only time) into overall output of 'outer' block (EB or SP) for *all* ES which runs inside it ?



 All   Comments   Change History   Subversion Commits      Sort Order: Ascending order - Click to sort in descending order
There are no comments yet on this issue.