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

Presence of Trace session affects stats/counts of indexed reads [CORE4797] #5095

Open
firebird-automations opened this issue May 17, 2015 · 4 comments

Comments

@firebird-automations
Copy link
Collaborator

Submitted by: @pavel-zotov

Following was done each run on empty database, page = 4k, FW = ON.

DDL:

create or alter view vmon as
select r.mon$record_seq_reads seq_reads,r.mon$record_idx_reads idx_reads
from mon$attachments a left join mon$record_stats r on a.mon$stat_id=r.mon$stat_id
where a.mon$attachment_id = current_connection;
commit;
recreate table test(x int);
commit;
insert into test select rand()*100 from (select 1 i from rdb$types rows 100) a, (select 1 i from rdb$types rows 100) b;
commit;
create index test_x on test(x);
commit; ------------------------------- [1]

TEST-1. Without trace.

select * from vmon; ----------------------- [a]
out nul; select min(x) from test; out;
commit;
select * from vmon; ----------------------- [b]

Result in 2.5:
~~~~~~~~~~

SEQ_READS IDX_READS
========= =====================
10173 382

SEQ_READS IDX_READS
========= =====================
10173 385

Difference of values in IDX_READS column is 385 - 382 = 3 rather than expected 1 (one).
The same result will be for: select x from test order by x rows 1;

Result in 3.0:
~~~~~~~~~~
SEQ_READS IDX_READS
========= =====================
10178 355

SEQ_READS IDX_READS
========= =====================
10178 357

Difference of values in IDX_READS column is 357 - 355 = 2 rather than expected 1 (one).
The same result will be for: select x from test order by x rows 1;

TEST-2. WITH trace launching after "commit; --------- [1]" and before first subsequent query to view "vmon".

select * from vmon; ----------------------- [a] -- this should be issued AFTER trace session will launched in another window
out nul; select min(x) from test; out;
commit;
select * from vmon; ----------------------- [b]

Result in 2.5:
~~~~~~~~~~
SEQ_READS IDX_READS
========== =====================
10173 382

SEQ_READS IDX_READS
========== =====================
10173 386

Difference of values in IDX_READS column is 386 - 382 = 4 rather than expected 1 (one). And this value differ from 3 that was received before, without trace.

Result in 3.0: the same as before, difference is 2 rather than 1. Trace has no affect on this.
~~~~~~~~~~

Q1: why differences in IDX_READS column never was 1 ?
Q2: how TRACE session could affect on result of gathering statistics in MON$RECORD_STATS in 2.5 ?!

PS. Tested on: WI-V2.5.5.26870 and WI-T3.0.0.31836, both - SuperClassic.

@firebird-automations
Copy link
Collaborator Author

Modified by: Sean Leyne (seanleyne)

summary: Number of indexed reads differ from expected and depends (only in 2.5) on presence of trace session => Presence of Trace session affects count of indexed reads

@firebird-automations
Copy link
Collaborator Author

Commented by: Sean Leyne (seanleyne)

Edited Summary for better readability

@firebird-automations
Copy link
Collaborator Author

Modified by: Sean Leyne (seanleyne)

summary: Presence of Trace session affects count of indexed reads => Presence of Trace session affects stats/counts of indexed reads

@firebird-automations
Copy link
Collaborator Author

Commented by: @pavel-zotov

Found something interesting for 2.5: difference between indexed_reads reporting by MON$ statistics equal to... number of data sources that participating in statement!

Example-1.

commit;
select * from vmon;

set term ^;
execute block as
declare n int = 10;
declare i int;
begin
while (n>0) do
begin
execute statement 'select min(a.x) from test a join test2 b on a.x = b.x' into i; -- 20; 22
n = n-1;
end
end
^
set term ;^

commit;
select * from vmon;

-- this will report difference = 20 if we run it without trace and 22 if trace will be active. Note that statement contains two data sources, test & test2.

Example-2.

...
execute statement 'select min(a.x) from test a join test b on a.x = b.x join test c on b.x = c.x' into i;
...

-- will report difference = 30 if we run it without trace and 33 if trace will be active. Note that statement contains three data sources, test, test2 & test3.

Also it was encountered that this difference appear ONLY when trace config:

1) contains print_plan true
AND
2) contains something that forces trace log to be filled with data, .i.e.:
time_threshold = 0
log_statement_finish true

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

1 participant