Open firebird-automations opened 3 years ago
Commented by: @dyemanov
AFAIU, this has almost nothing to do with EDS and should be reproducible with two regular attachments:
(1) create sequence, set it to 1 (2) select gen_id -- returns 1 (1) recreate sequence, set it to 2 (2) select gen_id -- using the same prepared statement as the first time! -- returns unexpected result
When the statement is prepared, generator name is converted to its internal ID (RDB$GENERATOR_ID) and later all GEN_IDs inside this statement read/write the generator using its ID (for performance reasons). RECREATE SEQUENCE drops the old generator and creates the new one, old ID becomes invalid and all subsequent GEN_IDs using the old ID will return zero (or maybe garbage -- not sure).
EDS just preserves the statement in the prepared state if the interval is less than ExtConnPoolLifeTime, thus showing you the issue.
I think the source of the issue is the lack of existence locks for generators, thus making it possible to drop the generator which is used by prepared statements -- what is usually prohibited for other objects.
Commented by: @pavel-zotov
> this has almost nothing to do with EDS and should be reproducible with two regular attachments
set bail on; set list on; shell if exist c:\temp\tmp4test.fdb del c:\temp\tmp4test.fdb; create database 'localhost:c:\temp\tmp4test.fdb' user SYSDBA password 'masterkey';
SET KEEP_TRAN_PARAMS ON; commit;
set transaction read committed no wait;
create sequence g; -- "(1) create sequence, set it to 1" select gen_id(g,10) from rdb$database; -- (2) select gen_id -- returns 1
select gen_id(g,0) as initial_seq_value from rdb$database; show sequ g; commit;
set term #; execute block returns(iter smallint, prepared_seq_value int, changed_seq_value int) as declare c int; begin for execute statement 'select row_number()over(), gen_id(g,0) from rdb$types rows 3' into iter, prepared_seq_value do begin execute statement 'recreate sequence g'; execute statement 'select gen_id(g,9) from rdb$database' into changed_seq_value; suspend; end end
set term ;# commit;
Output:
GEN_ID 10
INITIAL_SEQ_VALUE 10
Generator G, current value: 10, initial value: 1, increment: 1
ITER 1 PREPARED_SEQ_VALUE 10 CHANGED_SEQ_VALUE 9
ITER 2 PREPARED_SEQ_VALUE 10 <<< !! <<< CHANGED_SEQ_VALUE 18
ITER 3 PREPARED_SEQ_VALUE 10 <<< !! <<< CHANGED_SEQ_VALUE 27
FINAL_SEQ_VALUE 0 <<<<<<<<<<<<<< !!! <<<<<<<<<<<<<<
PS. Finally we get 0 (zero). Is this because of:
> old ID becomes invalid and all subsequent GEN_IDs using the old ID will return **zero** ...
-- ?
Commented by: @dyemanov
Your last test case is wrong because RECREATE SEQUENCE is not committed. And why again EXECUTE BLOCK + EXECUTE STATEMENT ? Two python connections is perfectly enough for the test.
Commented by: @pavel-zotov
> Your last test case is wrong because RECREATE SEQUENCE is not committed.
set bail on; set list on; shell if exist c:\temp\tmp4test.fdb del c:\temp\tmp4test.fdb; create database 'localhost:c:\temp\tmp4test.fdb' user SYSDBA password 'masterkey';
SET KEEP_TRAN_PARAMS ON; commit;
set transaction read committed no wait;
create sequence g; -- "(1) create sequence, set it to 1" select gen_id(g,10) from rdb$database; -- (2) select gen_id -- returns 1
select gen_id(g,0) as initial_seq_value from rdb$database; show sequ g; commit;
set transaction READ COMMITTED NO WAIT;
set term #; execute block returns(iter smallint, prepared_seq_value int, changed_seq_value int) as declare c int; begin for execute statement 'select row_number()over(), gen_id(g,0) from rdb$types rows 3' into iter, prepared_seq_value do begin execute statement 'recreate sequence g' WITH AUTONOMOUS TRANSACTION ; execute statement 'select gen_id(g,9) from rdb$database' WITH AUTONOMOUS TRANSACTION into changed_seq_value; suspend; end end
set term ;# commit;
> And why again EXECUTE BLOCK + EXECUTE STATEMENT ? Two python connections is perfectly enough for the test.
Pure ISQL is better and easier :-)
Commented by: @hvlad
Please, change the title and description to show actual issue (stale metadata for generator could be used, afaiu).
Submitted by: @pavel-zotov
Attachments: extpool-and-sequence.bat.7z
Steps to reproduce:
1) open firebird.conf and set ExtConnPoolLifeTime to value about 5...10 (I used 5); restart FB 4.x.
2) unpack batch from attached .7z; open it in editor and adjust following variables:
fbc // path to isql.exe from FB 4.x dbnm // name of temporary database usr // SYSDBA psw // masterkey
This batch will create temporary database and .sql which does:
1) connect to this temp database; 2) run 'RECREATE SEQUENCE g_eds_test;' 3) creates procedure 'sp_increment_sequence' (its name speaks for itself) 4) RECONNECT to database; 5) run procedure 'sp_increment_sequence' with input arg. = 123. 6) check that final value of sequence 'g_eds_test' is 123
Then batch will parse firebird.conf (from !fbc!\ folder) and take value ExtConnPoolLifeTime from there (it must be uncommented, of course).
Finally, it calls just created .sql *three* times, with different interval between second and third: firs interval = (ExtConnPoolLifeTime + 1), second is (ExtConnPoolLifeTime - 1), i.e.:
t0 --> run #1 t1 = return from sql (i.e. finish of run #1)
.... wait for (ExtConnPoolLifeTime + 1) seconds ....
t2 = t1 + (ExtConnPoolLifeTime + 1) seconds --> run #2 t3 = return from sql (i.e. finish of run #2)
.... wait for (ExtConnPoolLifeTime - 1) seconds ....
t4 = t3 + (ExtConnPoolLifeTime - 1) seconds --> run #3
Built-in Windows utility 'timeout' is used for pausesbetween launches of isql.
Here is the content of SQL:
set bail on; set heading off; set list on; connect 'localhost:c:\temp\tmp4test.fdb' user SYSDBA password 'masterkey'; create or alter procedure sp_increment_sequence(a_inc int = null) as begin end;
recreate view v_check as select cast('now' as timestamp) dts, coalesce( q'{YES, '}' || trim(g.rdb$generator_name) || q'{' exists.}', q'{NO, it doesn't}') as "Does sequence 'g_eds_test' exists ? =>" from rdb$database r left join rdb$generators g on upper(g.rdb$generator_name) = upper('g_eds_test'); commit;
select 'point-1' as msg, v.* from v_check v; recreate sequence g_eds_test; commit; select 'point-2' as msg, v.* from v_check v;
select gen_id(g_eds_test, 0) as init_seq_value from rdb$database; commit;
set term #; create or alter procedure sp_increment_sequence(a_inc int = null) returns(gen_value_before_inc int, gen_value_after__inc int) as declare c int; begin gen_value_before_inc = gen_id(g_eds_test,0); c = gen_id( g_eds_test, coalesce(a_inc,1) ); gen_value_after__inc = gen_id(g_eds_test,0); suspend; end
commit
-- ### RECONNECT ### connect 'localhost:c:\temp\tmp4test.fdb' user SYSDBA password 'masterkey'
select gen_id(g_eds_test, 0) as seq_value_after_reconnect from rdb$database
commit
execute block returns(gen_value_before_inc int, gen_value_after__inc int) as begin execute statement ( 'select gen_value_before_inc, gen_value_after__inc from sp_increment_sequence( ? )' ) ( 123 ) on external 'localhost:' || rdb$get_context('SYSTEM','DB_NAME') as user 'SYSDBA' password 'masterkey' -- role 'A' || replace(lpad('',30,uuid_to_char(gen_uuid())),'-','') --------------------------------------------- ::::: NB ::::: into gen_value_before_inc, gen_value_after__inc ; suspend; end
set term ;#
select iif( gen_id(g_eds_test, 0) > 0, 'Expected: ' || gen_id(g_eds_test,0), 'UNEXPECTED >>> ' || gen_id(g_eds_test,0) || ' <<< ?' ) as final_seq_value from rdb$database; commit;
drop procedure sp_increment_sequence; drop sequence g_eds_test; commit;
select 'point-3' as msg, v.* from v_check v; commit;
set list off; set heading off; select '=== bye-bye from SQL ===' from rdb$database;
PLEASE NOTE ON COMMENTED LINE: " -- role 'A' || replace(lpad('',30,uuid_to_char(gen_uuid())),'-','') --------------------------------------------- ::::: NB :::::"
Run this batch.
This is result of batch when it runs with ExtConnPoolLifeTime = 5:
###############################
MSG point-1 DTS 2021-01-07 10:30:04.5180 Does sequence 'g_eds_test' exists ? => NO, it doesn't
MSG point-2 DTS 2021-01-07 10:30:04.5290 Does sequence 'g_eds_test' exists ? => YES, 'G_EDS_TEST' exists.
INIT_SEQ_VALUE 0
SEQ_VALUE_AFTER_RECONNECT 0
GEN_VALUE_BEFORE_INC 0 GEN_VALUE_AFTER__INC 123
FINAL_SEQ_VALUE Expected: 123
MSG point-3 DTS 2021-01-07 10:30:05.0920 Does sequence 'g_eds_test' exists ? => NO, it doesn't
=== bye-bye from SQL ===
Take delay for 6 s, i.e. ### GREATER ### than ECP lifetime. . .
Waiting for 6 seconds, press a key to continue ...5 4 3 2 1 0
Check result after "long delay":
MSG point-1 DTS 2021-01-07 10:30:11.5640 Does sequence 'g_eds_test' exists ? => NO, it doesn't
MSG point-2 DTS 2021-01-07 10:30:11.5790 Does sequence 'g_eds_test' exists ? => YES, 'G_EDS_TEST' exists.
INIT_SEQ_VALUE 0
SEQ_VALUE_AFTER_RECONNECT 0
GEN_VALUE_BEFORE_INC 0 GEN_VALUE_AFTER__INC 123
FINAL_SEQ_VALUE Expected: 123
MSG point-3 DTS 2021-01-07 10:30:12.1600 Does sequence 'g_eds_test' exists ? => NO, it doesn't
=== bye-bye from SQL ===
Take delay for 4 s, i.e. ### SHORTER ### than ECP lifetime. . .
Waiting for 4 seconds, press a key to continue ...3 2 1 0
Check result after "short delay":
MSG point-1 DTS 2021-01-07 10:30:16.2370 Does sequence 'g_eds_test' exists ? => NO, it doesn't
MSG point-2 DTS 2021-01-07 10:30:16.2560 Does sequence 'g_eds_test' exists ? => YES, 'G_EDS_TEST' exists.
INIT_SEQ_VALUE 0
SEQ_VALUE_AFTER_RECONNECT 0
GEN_VALUE_BEFORE_INC 123 GEN_VALUE_AFTER__INC 246
FINAL_SEQ_VALUE UNEXPECTED >>> 0 <<< ?
MSG point-3 DTS 2021-01-07 10:30:16.3380 Does sequence 'g_eds_test' exists ? => NO, it doesn't
=== bye-bye from SQL ===
###############################
As you can see, sequence is recreated every time. But its *OLD* value (123) still visible to procedure 'sp_increment_sequence' when it is called via ES/EDS and - most important - time from previous call is less then ExtConnPoolLifeTime.
If we uncomment line "-- role 'A' || replace(lpad('',30,uuid_to_char(gen_uuid())),'-','')" and repeat than result is expected:
GEN_VALUE_BEFORE_INC 0 GEN_VALUE_AFTER__INC 123 FINAL_SEQ_VALUE Expected: 123
(using ROLE clause with random value forces EDS mechanism to create totally new connection, AFAIK).
PS. WI-V4.0.0.2307 Firebird 4.0 Release Candidate 1
PPS. UPD, 03.02.21. Changed title after Vlad's request.