Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
firebird-automations opened this issue Jun 2, 2014 · 1 comment

Comments

@firebird-automations
Copy link
Collaborator

Submitted by: @pavel-zotov

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 ?

@firebird-automations
Copy link
Collaborator Author

Modified by: @hvlad

assignee: Vlad Khorsun [ hvlad ]

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants