Repository navigation
Profiler reports wrong or missing PSQL line statistics #9220
Description
PLG$PROF_PSQL_STATS (and PLG$PROF_PSQL_STATS_VIEW) has wrong data for some common PSQL constructs:
-
FOR SELECT / FOR EXECUTE STATEMENT loops are counted wrong.
The profiler only changes the current line when a statement starts. The next fetch of the loop
does not start the FOR statement again, so:- the FOR line counts 1 (only the open), not one per fetch;
- the time of each fetch is charged to the last line of the loop body;
- when the body has only one statement, the current line never changes, so the body line also
counts 1 instead of the number of iterations.
-
Some statements are not in the report at all.
DSQL wraps some statements in internal BLR nodes, and the source line/column is attached to the
wrapper instead of the statement:- DML,
EXCEPTION,EXECUTE STATEMENTandMERGEin a block that hasWHENhandlers; UPDATE OR INSERT, always;FOR EXECUTE STATEMENT, always.
Those lines are missing from the stats, and their time is charged to the line before them.
- DML,
Test case
create database 'profiler-test.fdb';
create table t (id integer);
insert into t select row_number() over () from rdb$types rows 5;
commit;
select rdb$profiler.start_session('test') from rdb$database;
set term !;
execute block as
declare n integer = 0;
begin
for select id from t into :n do
n = n + 1;
end!
execute block as
declare n integer = 0;
begin
insert into t values (100);
update or insert into t values (101) matching (id);
for execute statement 'select id from t' into :n do
n = n + 1;
when any do
n = 0;
end!
set term ;!
execute procedure rdb$profiler.finish_session(true);
commit;
select statement_id, line_num, column_num, counter
from plg$profiler.plg$prof_psql_stats_view
order by statement_id, line_num, column_num;
drop database;Current result
First block (5 rows):
| line | statement | counter |
|---|---|---|
| 2 | declare n ... |
1 |
| 4 | for select ... |
1 |
| 5 | n = n + 1 |
1 |
Second block (7 rows): lines 4 (insert), 5 (update or insert) and 6 (for execute statement) are
missing, and line 7 (n = n + 1) counts 1.
Expected result
First block:
| line | statement | counter |
|---|---|---|
| 2 | declare n ... |
1 |
| 4 | for select ... |
6 (open + 5 fetches) |
| 5 | n = n + 1 |
5 |
Second block:
| line | statement | counter |
|---|---|---|
| 2 | declare n ... |
1 |
| 3 | begin (block with WHEN) |
1 |
| 4 | insert ... |
1 |
| 5 | update or insert ... |
1 |
| 6 | for execute statement |
8 (open + 7 fetches) |
| 7 | n = n + 1 |
7 |
Fetch time should be charged to the FOR line, not to the loop body.
The missing lines can be fixed when the BLR is parsed, so routines already stored in a database
get correct stats without being recompiled.
Activity
Fix FirebirdSQL#9220 - Profiler reports wrong or missing PSQL line st…