Jump to: output_first_mismatch    outcomes_full_history    elapsed_time_chart
Show cross-report outcomes.

Annotation type Annotation details
2 @message
assert   
    WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
    ============ ======= ======= ======================================== ========== ======== ========
    TMP_ECP_FREQ       1       1 NEW                                               0        0 python
    TMP_ECP_FREQ       2       2 NEW                                               0        0 python
    TMP_ECP_FREQ       3       3 NEW                                               0        0 python
    TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
    TMP_ECP_FREQ       4       5 RUN DML                                           0        0 firebird
    TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
    TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
    TMP_ECP_FREQ       1       8 BYE                                               0        1 python
  + TMP_ECP_FREQ       4       9 BYE                                               0        0 firebird
  - TMP_ECP_FREQ       5       9 NEW                                               0        0 firebird
  + TMP_ECP_FREQ       5      10 NEW                                               0        0 firebird
  - TMP_ECP_FREQ       5      10 RUN DML                                           0        0 firebird
  + TMP_ECP_FREQ       5      11 RUN DML                                           0        0 firebird
  - TMP_ECP_FREQ       5      11 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
  + TMP_ECP_FREQ       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
  - TMP_ECP_FREQ       5      12 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
  + TMP_ECP_FREQ       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
  - TMP_ECP_FREQ       4      13 BYE                                               0        0 firebird
    TMP_ECP_FREQ       2      14 BYE                                               0        1 python
    TMP_ECP_FREQ       6      15 NEW                                               0        0 firebird
    TMP_ECP_FREQ       6      16 RUN DML                                           0        0 firebird
    TMP_ECP_FREQ       6      17 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
    TMP_ECP_FREQ       6      18 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
    TMP_ECP_FREQ       6      19 BYE                                               0        0 firebird
  - TMP_ECP_FREQ       3      20 BYE                                               0        0 python
  - TMP_ECP_FREQ       5      21 BYE                                               0        0 firebird
  + TMP_ECP_FREQ       5      20 BYE                                               0        0 firebird
  + TMP_ECP_FREQ       3      21 BYE                                               0        0 python
    TMP_ECP_RARE       1       1 NEW                                               0        0 python
    TMP_ECP_RARE       2       2 NEW                                               0        0 python
    TMP_ECP_RARE       3       3 NEW                                               0        0 python
    TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
    TMP_ECP_RARE       4       5 RUN DML                                           0        0 firebird
    TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
    TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
    TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
    TMP_ECP_RARE       1       9 BYE                                               0        0 python
    TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
    TMP_ECP_RARE       5      11 RUN DML                                           0        0 firebird
    TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
    TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
    TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
    TMP_ECP_RARE       2      15 BYE                                               0        0 python
    TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
    TMP_ECP_RARE       6      17 RUN DML                                           0        0 firebird
    TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
    TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
    TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
    TMP_ECP_RARE       3      21 BYE                                               0        0 python

LOG DETAILS:

2024-08-09 14:21:12.984
2024-08-09 14:21:12.989 act = <firebird.qa.plugin.Action object at [hex]>
2024-08-09 14:21:12.993 tmp_user_freq = <firebird.qa.plugin.User object at [hex]>
2024-08-09 14:21:12.998 tmp_user_rare = <firebird.qa.plugin.User object at [hex]>
2024-08-09 14:21:13.003 tmp_cleaner_role = <firebird.qa.plugin.Role object at [hex]>
2024-08-09 14:21:13.008 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-08-09 14:21:13.012
2024-08-09 14:21:13.017 @pytest.mark.es_eds
2024-08-09 14:21:13.022 @pytest.mark.version('>=4.0')
2024-08-09 14:21:13.026 def test_1(act: Action, tmp_user_freq: User, tmp_user_rare: User, tmp_cleaner_role: Role, capsys):
2024-08-09 14:21:13.031
2024-08-09 14:21:13.036 # [doc] state of external connections pool could be queried using ...:
2024-08-09 14:21:13.041 # - EXT_CONN_POOL_SIZE			pool size
2024-08-09 14:21:13.046 # - EXT_CONN_POOL_LIFETIME		idle connection lifetime, in seconds
2024-08-09 14:21:13.051 ECP_SIZE, ECP_LIFE = -1, -1
2024-08-09 14:21:13.056 with act.db.connect() as con:
2024-08-09 14:21:13.060 with con.cursor() as cur:
2024-08-09 14:21:13.065 cur.execute("select cast(rdb$get_context('SYSTEM', 'EXT_CONN_POOL_SIZE') as int), cast(rdb$get_context('SYSTEM', 'EXT_CONN_POOL_LIFETIME') as int) from rdb$database")
2024-08-09 14:21:13.070 ECP_SIZE, ECP_LIFE = cur.fetchone()
2024-08-09 14:21:13.075 assert ECP_SIZE > 1;
2024-08-09 14:21:13.082
2024-08-09 14:21:13.087 SERVER_MODE = act.get_server_architecture()
2024-08-09 14:21:13.094 sql_init = f'''
2024-08-09 14:21:13.106 set bail on;
2024-08-09 14:21:13.113 set list on;
2024-08-09 14:21:13.121 set wng off;
2024-08-09 14:21:13.129 alter database set linger to {ECP_LIFE+ADD_DELAY_FOR_RARE+2};
2024-08-09 14:21:13.137 alter role {tmp_cleaner_role.name} set system privileges to MODIFY_EXT_CONN_POOL;
2024-08-09 14:21:13.149 commit;
2024-08-09 14:21:13.154
2024-08-09 14:21:13.163 grant default {tmp_cleaner_role.name} to user {tmp_user_freq.name};
2024-08-09 14:21:13.169 grant default {tmp_cleaner_role.name} to user {tmp_user_rare.name};
2024-08-09 14:21:13.180 commit;
2024-08-09 14:21:13.189
2024-08-09 14:21:13.194 set term ^;
2024-08-09 14:21:13.199 create function fn_get_bin_name() returns varchar(255) as
2024-08-09 14:21:13.205 declare v_bin_name varchar(255);
2024-08-09 14:21:13.210 begin
2024-08-09 14:21:13.219 v_bin_name = rdb$get_context('SYSTEM','CLIENT_PROCESS');
2024-08-09 14:21:13.224
2024-08-09 14:21:13.230 -- ::: NOTE ::: Python binary can have numeric suffixes on Linux:
2024-08-09 14:21:13.235 if (v_bin_name similar to '%((\\python([[:DIGIT:]]+%)?.exe)|(/python([[:DIGIT:]]+%)?))') then
2024-08-09 14:21:13.243 return 'python'; -- '/usr/bin/python3.9' ==> 'python'
2024-08-09 14:21:13.249
2024-08-09 14:21:13.259 if (v_bin_name similar to '%((\\firebird([[:DIGIT:]]+%)?.exe)|(/python([[:DIGIT:]]+%)?))') then
2024-08-09 14:21:13.265 return 'firebird';
2024-08-09 14:21:13.276
2024-08-09 14:21:13.281 -- Extracts file name from full path of client binary process.
2024-08-09 14:21:13.292 -- For Windows: removes extension, in order returning name be the same as on Linux.
2024-08-09 14:21:13.301 -- 'c:\\program files\\firebird30\\firebird.exe' --> 'firebird'
2024-08-09 14:21:13.306 -- '/opt/firebird/bin/firebird'                  --> 'firebird'
2024-08-09 14:21:13.315 -- ::: NOTE ::: backslash must be duplicated when using this DDL in any Python
2024-08-09 14:21:13.321 -- environment otherwise it will be swallowed
2024-08-09 14:21:13.325 return
2024-08-09 14:21:13.330 (
2024-08-09 14:21:13.335 select
2024-08-09 14:21:13.340 --p
2024-08-09 14:21:13.344 --,r
2024-08-09 14:21:13.349 --,ext_pos
2024-08-09 14:21:13.354 --,n
2024-08-09 14:21:13.358 --,x
2024-08-09 14:21:13.363 reverse(left(x,n)) as clnt_bin
2024-08-09 14:21:13.368 -- reverse(x)  as clnt_bin
2024-08-09 14:21:13.373 from
2024-08-09 14:21:13.377 (
2024-08-09 14:21:13.382 select
2024-08-09 14:21:13.387 p
2024-08-09 14:21:13.392 ,reverse(p) r
2024-08-09 14:21:13.397 ,ext_pos
2024-08-09 14:21:13.402 ,substring(reverse(p) from iif( is_win, ext_pos+1, 1) ) x
2024-08-09 14:21:13.407 ,position( '|' in replace(replace(reverse( p ),'\\','|'),'/','|') ) - iif(is_win, ext_pos+1, 1) as n
2024-08-09 14:21:13.412 from (
2024-08-09 14:21:13.416 select
2024-08-09 14:21:13.421 trim(p) as p
2024-08-09 14:21:13.426 ,position( '\\' in p ) > 0 as is_win
2024-08-09 14:21:13.431 ,iif( position( '\\' in p ) > 0, position('.' in reverse(trim(p))), 0) as ext_pos
2024-08-09 14:21:13.435 from (
2024-08-09 14:21:13.440 select rdb$get_context('SYSTEM','CLIENT_PROCESS') as p from rdb$database
2024-08-09 14:21:13.445 )
2024-08-09 14:21:13.450 )
2024-08-09 14:21:13.454 )
2024-08-09 14:21:13.459 );
2024-08-09 14:21:13.464
2024-08-09 14:21:13.469 end
2024-08-09 14:21:13.473 ^
2024-08-09 14:21:13.478 set term ;^
2024-08-09 14:21:13.483
2024-08-09 14:21:13.487
2024-08-09 14:21:13.492 create table ecp_audit(
2024-08-09 14:21:13.497 id smallint generated by default as identity constraint pk_audit primary key
2024-08-09 14:21:13.501 ,srvmode varchar(12) -- 'Super' / 'SuperClassic' / 'Classic'
2024-08-09 14:21:13.506 ,who varchar(12) default current_user -- 'TMP_ECP_FREQ' / 'TMP_ECP_RARE' / 'SYSDBA'
2024-08-09 14:21:13.511 ,evt varchar(40) not null
2024-08-09 14:21:13.515 ,att smallint default current_connection
2024-08-09 14:21:13.524 ,trn smallint default current_transaction
2024-08-09 14:21:13.530 ,dts timestamp default 'now'
2024-08-09 14:21:13.534 ,pool_active_count smallint
2024-08-09 14:21:13.543 ,pool_idle_count smallint
2024-08-09 14:21:13.551 ,clnt_bin varchar(8)
2024-08-09 14:21:13.556 ,aux_info varchar(100)
2024-08-09 14:21:13.561 );
2024-08-09 14:21:13.565
2024-08-09 14:21:13.570 create view v_ecp_audit as
2024-08-09 14:21:13.575 select
2024-08-09 14:21:13.580 who
2024-08-09 14:21:13.585 ,att
2024-08-09 14:21:13.589 ,id
2024-08-09 14:21:13.594 ,evt
2024-08-09 14:21:13.600 ,active_cnt
2024-08-09 14:21:13.605 ,idle_cnt
2024-08-09 14:21:13.610 ,clnt_bin
2024-08-09 14:21:13.615 from (
2024-08-09 14:21:13.620 select
2024-08-09 14:21:13.624 srvmode
2024-08-09 14:21:13.629 ,who
2024-08-09 14:21:13.634 ,cast(dense_rank()over(partition by who order by att) as smallint) as att
2024-08-09 14:21:13.644 ,cast(dense_rank()over(partition by who order by id) as smallint) as id
2024-08-09 14:21:13.649 ,evt
2024-08-09 14:21:13.656 ,trn
2024-08-09 14:21:13.665 ,pool_active_count as active_cnt
2024-08-09 14:21:13.670 ,pool_idle_count as idle_cnt
2024-08-09 14:21:13.681 ,clnt_bin
2024-08-09 14:21:13.686 from ecp_audit
2024-08-09 14:21:13.697 )
2024-08-09 14:21:13.702 order by who, id
2024-08-09 14:21:13.707 ;
2024-08-09 14:21:13.712
2024-08-09 14:21:13.717
2024-08-09 14:21:13.722 grant select,insert on ecp_audit to public;
2024-08-09 14:21:13.726 grant select on v_ecp_audit to public;
2024-08-09 14:21:13.731 commit;
2024-08-09 14:21:13.736
2024-08-09 14:21:13.741 set term ^;
2024-08-09 14:21:13.745 create or alter trigger trg_aud_bi for ecp_audit active before insert sql security definer as
2024-08-09 14:21:13.754 declare v_srvmode varchar(30);
2024-08-09 14:21:13.759 declare p int;
2024-08-09 14:21:13.764 begin
2024-08-09 14:21:13.773 new.srvmode = '{SERVER_MODE}';
2024-08-09 14:21:13.778 new.pool_active_count = rdb$get_context('SYSTEM','EXT_CONN_POOL_ACTIVE_COUNT');
2024-08-09 14:21:13.789 new.pool_idle_count = rdb$get_context('SYSTEM','EXT_CONN_POOL_IDLE_COUNT');
2024-08-09 14:21:13.794 new.clnt_bin = right(fn_get_bin_name(), 8);
2024-08-09 14:21:13.799 -- right(rdb$get_context('SYSTEM','CLIENT_PROCESS'),15);
2024-08-09 14:21:13.807 end
2024-08-09 14:21:13.815 ^
2024-08-09 14:21:13.820
2024-08-09 14:21:13.825 create or alter trigger trg_connect inactive on connect sql security definer as
2024-08-09 14:21:13.830 declare p smallint;
2024-08-09 14:21:13.834 begin
2024-08-09 14:21:13.839 if (current_user <> '{act.db.user}') then
2024-08-09 14:21:13.844 begin
2024-08-09 14:21:13.849
2024-08-09 14:21:13.853 insert into ecp_audit(
2024-08-09 14:21:13.858 evt
2024-08-09 14:21:13.863 ) values (
2024-08-09 14:21:13.867 iif(resetting, 'TAKE FROM POOL: IDLE -> ACTIVE', 'NEW')
2024-08-09 14:21:13.872 );
2024-08-09 14:21:13.877 end
2024-08-09 14:21:13.881 end
2024-08-09 14:21:13.886 ^
2024-08-09 14:21:13.890
2024-08-09 14:21:13.895 create or alter trigger trg_disconnect inactive on disconnect sql security definer as
2024-08-09 14:21:13.904 begin
2024-08-09 14:21:13.911 if (current_user <> '{act.db.user}') then
2024-08-09 14:21:13.919 begin
2024-08-09 14:21:13.927 insert into ecp_audit(
2024-08-09 14:21:13.935 evt
2024-08-09 14:21:13.943 ) values (
2024-08-09 14:21:13.951 iif(resetting, 'MOVE INTO POOL: ACTIVE -> IDLE', 'BYE')
2024-08-09 14:21:13.961 );
2024-08-09 14:21:13.966 end
2024-08-09 14:21:13.971 end
2024-08-09 14:21:13.976 ^
2024-08-09 14:21:13.981 set term ;^
2024-08-09 14:21:13.986 commit;
2024-08-09 14:21:13.996 alter trigger trg_connect active;
2024-08-09 14:21:14.001 alter trigger trg_disconnect active;
2024-08-09 14:21:14.007 commit;
2024-08-09 14:21:14.012 '''
2024-08-09 14:21:14.019
2024-08-09 14:21:14.024 act.expected_stdout = ''
2024-08-09 14:21:14.029 act.isql(switches = ['-q'], input = sql_init, combine_output = True, io_enc = locale.getpreferredencoding())
2024-08-09 14:21:14.035 assert act.clean_stdout == act.clean_expected_stdout
2024-08-09 14:21:14.041 act.reset()
2024-08-09 14:21:14.052
2024-08-09 14:21:14.057 #-----------------------------------------------------
2024-08-09 14:21:14.062
2024-08-09 14:21:14.067 sql_for_run = '''
2024-08-09 14:21:14.076 execute block as
2024-08-09 14:21:14.081 declare c int;
2024-08-09 14:21:14.089 begin
2024-08-09 14:21:14.097 execute statement ( q'{ insert into ecp_audit( evt ) values( 'RUN DML') }' )
2024-08-09 14:21:14.109 on external
2024-08-09 14:21:14.115 'localhost:' || rdb$get_context('SYSTEM','DB_NAME')
2024-08-09 14:21:14.121 with autonomous transaction -- <<< !!! THIS IS MANDATORY IF WE WANT TO USE EXT CONN POOL !!! <<<
2024-08-09 14:21:14.128 as user current_user password '123'
2024-08-09 14:21:14.134 ;
2024-08-09 14:21:14.145 end
2024-08-09 14:21:14.150 '''
2024-08-09 14:21:14.156
2024-08-09 14:21:14.161 for usr in (tmp_user_freq, tmp_user_rare):
2024-08-09 14:21:14.167 conn_list = []
2024-08-09 14:21:14.172 for i in range(0, ITER_LOOP_CNT):
2024-08-09 14:21:14.177 conn_list.append( act.db.connect(user = usr.name, password = usr.password) )
2024-08-09 14:21:14.182
2024-08-09 14:21:14.187 for i,c in enumerate(conn_list):
2024-08-09 14:21:14.192
2024-08-09 14:21:14.197 # ::: NOTE :::
2024-08-09 14:21:14.203 # ::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
2024-08-09 14:21:14.208 # On every iteration DIFFERENT connection is used for run ES/EDS,
2024-08-09 14:21:14.213 # but all of them use the same user/password/role, so apropriate
2024-08-09 14:21:14.219 # item in the ExtConnPool can be used to run this statement.
2024-08-09 14:21:14.227 # But this will be so only for user = 'FREQ' because he does such
2024-08-09 14:21:14.233 # actions 'frequently': each (<ECP_LIFE> - 2) seconds.
2024-08-09 14:21:14.238 # For user 'RARE' new attachment will be created every time when
2024-08-09 14:21:14.243 # he runs ES/EDS because he does that 'rarely' and idle connection
2024-08-09 14:21:14.252 # (from his previous iteration) is removed from ExtConnPool due to
2024-08-09 14:21:14.257 # expiration of ExtConnPoolLifeTime:
2024-08-09 14:21:14.267 # ::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
2024-08-09 14:21:14.272 try:
2024-08-09 14:21:14.278 #c.execute_immediate( sql_for_run )
2024-08-09 14:21:14.283 with c.cursor() as cur:
2024-08-09 14:21:14.289 cur.execute(sql_for_run)
2024-08-09 14:21:14.294
2024-08-09 14:21:14.304 if i < len(conn_list)-1:
2024-08-09 14:21:14.312 time.sleep( 1 if usr == tmp_user_freq else ECP_LIFE + ADD_DELAY_FOR_RARE )
2024-08-09 14:21:14.320 else:
2024-08-09 14:21:14.332 c.execute_immediate( 'ALTER EXTERNAL CONNECTIONS POOL CLEAR ALL' )
2024-08-09 14:21:14.341 finally:
2024-08-09 14:21:14.349 if c:
2024-08-09 14:21:14.357 c.close()
2024-08-09 14:21:14.362
2024-08-09 14:21:14.372 if SERVER_MODE == 'Classic':
2024-08-09 14:21:14.378 act.expected_stdout = """
2024-08-09 14:21:14.388 WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
2024-08-09 14:21:14.393 ============ ======= ======= ======================================== ========== ======== ========
2024-08-09 14:21:14.400 TMP_ECP_FREQ       1       1 NEW                                               0        0 python
2024-08-09 14:21:14.410 TMP_ECP_FREQ       2       2 NEW                                               0        0 python
2024-08-09 14:21:14.415 TMP_ECP_FREQ       3       3 NEW                                               0        0 python
2024-08-09 14:21:14.424 TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:14.431 TMP_ECP_FREQ       4       5 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.439 TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.445 TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.455 TMP_ECP_FREQ       1       8 BYE                                               0        1 python
2024-08-09 14:21:14.461 TMP_ECP_FREQ       5       9 NEW                                               0        0 firebird
2024-08-09 14:21:14.466 TMP_ECP_FREQ       5      10 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.472 TMP_ECP_FREQ       5      11 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.481 TMP_ECP_FREQ       5      12 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.486 TMP_ECP_FREQ       4      13 BYE                                               0        0 firebird
2024-08-09 14:21:14.496 TMP_ECP_FREQ       2      14 BYE                                               0        1 python
2024-08-09 14:21:14.504 TMP_ECP_FREQ       6      15 NEW                                               0        0 firebird
2024-08-09 14:21:14.509 TMP_ECP_FREQ       6      16 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.520 TMP_ECP_FREQ       6      17 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.527 TMP_ECP_FREQ       6      18 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.536 TMP_ECP_FREQ       6      19 BYE                                               0        0 firebird
2024-08-09 14:21:14.544 TMP_ECP_FREQ       3      20 BYE                                               0        0 python
2024-08-09 14:21:14.554 TMP_ECP_FREQ       5      21 BYE                                               0        0 firebird
2024-08-09 14:21:14.564 TMP_ECP_RARE       1       1 NEW                                               0        0 python
2024-08-09 14:21:14.573 TMP_ECP_RARE       2       2 NEW                                               0        0 python
2024-08-09 14:21:14.578 TMP_ECP_RARE       3       3 NEW                                               0        0 python
2024-08-09 14:21:14.588 TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:14.594 TMP_ECP_RARE       4       5 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.599 TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.604 TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.609 TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
2024-08-09 14:21:14.614 TMP_ECP_RARE       1       9 BYE                                               0        0 python
2024-08-09 14:21:14.619 TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
2024-08-09 14:21:14.624 TMP_ECP_RARE       5      11 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.629 TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.634 TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.639 TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
2024-08-09 14:21:14.644 TMP_ECP_RARE       2      15 BYE                                               0        0 python
2024-08-09 14:21:14.649 TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
2024-08-09 14:21:14.654 TMP_ECP_RARE       6      17 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.659 TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.664 TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.669 TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
2024-08-09 14:21:14.674 TMP_ECP_RARE       3      21 BYE                                               0        0 python
2024-08-09 14:21:14.679 """
2024-08-09 14:21:14.684 else:
2024-08-09 14:21:14.689 act.expected_stdout = """
2024-08-09 14:21:14.695 WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
2024-08-09 14:21:14.700 ============ ======= ======= ======================================== ========== ======== ========
2024-08-09 14:21:14.705 TMP_ECP_FREQ       1       1 NEW                                               0        0 python
2024-08-09 14:21:14.710 TMP_ECP_FREQ       2       2 NEW                                               0        0 python
2024-08-09 14:21:14.715 TMP_ECP_FREQ       3       3 NEW                                               0        0 python
2024-08-09 14:21:14.720 TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:14.725 TMP_ECP_FREQ       4       5 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.730 TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.735 TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.740 TMP_ECP_FREQ       1       8 BYE                                               0        1 python
2024-08-09 14:21:14.745 TMP_ECP_FREQ       4       9 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.750 TMP_ECP_FREQ       4      10 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.755 TMP_ECP_FREQ       4      11 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.760 TMP_ECP_FREQ       2      12 BYE                                               0        1 python
2024-08-09 14:21:14.765 TMP_ECP_FREQ       4      13 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.770 TMP_ECP_FREQ       4      14 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.776 TMP_ECP_FREQ       4      15 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.781 TMP_ECP_FREQ       4      16 BYE                                               0        0 firebird
2024-08-09 14:21:14.786 TMP_ECP_FREQ       3      17 BYE                                               0        0 python
2024-08-09 14:21:14.791 TMP_ECP_RARE       1       1 NEW                                               0        0 python
2024-08-09 14:21:14.796 TMP_ECP_RARE       2       2 NEW                                               0        0 python
2024-08-09 14:21:14.801 TMP_ECP_RARE       3       3 NEW                                               0        0 python
2024-08-09 14:21:14.807 TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:14.813 TMP_ECP_RARE       4       5 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.821 TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.831 TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.841 TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
2024-08-09 14:21:14.847 TMP_ECP_RARE       1       9 BYE                                               0        0 python
2024-08-09 14:21:14.855 TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
2024-08-09 14:21:14.860 TMP_ECP_RARE       5      11 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.866 TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.871 TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.876 TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
2024-08-09 14:21:14.881 TMP_ECP_RARE       2      15 BYE                                               0        0 python
2024-08-09 14:21:14.886 TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
2024-08-09 14:21:14.892 TMP_ECP_RARE       6      17 RUN DML                                           1        0 firebird
2024-08-09 14:21:14.897 TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
2024-08-09 14:21:14.902 TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
2024-08-09 14:21:14.907 TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
2024-08-09 14:21:14.912 TMP_ECP_RARE       3      21 BYE                                               0        0 python
2024-08-09 14:21:14.917 """
2024-08-09 14:21:14.922 act.isql(switches = ['-q', '-pag', '999999'], input = 'select who,att,id,evt,active_cnt,idle_cnt,clnt_bin from v_ecp_audit;', combine_output = True, io_enc = locale.getpreferredencoding())
2024-08-09 14:21:14.927 >       assert act.clean_stdout == act.clean_expected_stdout
2024-08-09 14:21:14.932 E       assert
2024-08-09 14:21:14.937 E           WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
2024-08-09 14:21:14.942 E           ============ ======= ======= ======================================== ========== ======== ========
2024-08-09 14:21:14.947 E           TMP_ECP_FREQ       1       1 NEW                                               0        0 python
2024-08-09 14:21:14.952 E           TMP_ECP_FREQ       2       2 NEW                                               0        0 python
2024-08-09 14:21:14.957 E           TMP_ECP_FREQ       3       3 NEW                                               0        0 python
2024-08-09 14:21:14.962 E           TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:14.967 E           TMP_ECP_FREQ       4       5 RUN DML                                           0        0 firebird
2024-08-09 14:21:14.972 E           TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:14.976 E           TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:14.981 E           TMP_ECP_FREQ       1       8 BYE                                               0        1 python
2024-08-09 14:21:14.989 E         + TMP_ECP_FREQ       4       9 BYE                                               0        0 firebird
2024-08-09 14:21:14.994 E         - TMP_ECP_FREQ       5       9 NEW                                               0        0 firebird
2024-08-09 14:21:15.006 E         + TMP_ECP_FREQ       5      10 NEW                                               0        0 firebird
2024-08-09 14:21:15.017 E         - TMP_ECP_FREQ       5      10 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.031 E         + TMP_ECP_FREQ       5      11 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.048 E         - TMP_ECP_FREQ       5      11 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.062 E         + TMP_ECP_FREQ       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.078 E         - TMP_ECP_FREQ       5      12 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.092 E         + TMP_ECP_FREQ       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.109 E         - TMP_ECP_FREQ       4      13 BYE                                               0        0 firebird
2024-08-09 14:21:15.117 E           TMP_ECP_FREQ       2      14 BYE                                               0        1 python
2024-08-09 14:21:15.125 E           TMP_ECP_FREQ       6      15 NEW                                               0        0 firebird
2024-08-09 14:21:15.130 E           TMP_ECP_FREQ       6      16 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.135 E           TMP_ECP_FREQ       6      17 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.141 E           TMP_ECP_FREQ       6      18 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.146 E           TMP_ECP_FREQ       6      19 BYE                                               0        0 firebird
2024-08-09 14:21:15.152 E         - TMP_ECP_FREQ       3      20 BYE                                               0        0 python
2024-08-09 14:21:15.157 E         - TMP_ECP_FREQ       5      21 BYE                                               0        0 firebird
2024-08-09 14:21:15.167 E         + TMP_ECP_FREQ       5      20 BYE                                               0        0 firebird
2024-08-09 14:21:15.181 E         + TMP_ECP_FREQ       3      21 BYE                                               0        0 python
2024-08-09 14:21:15.186 E           TMP_ECP_RARE       1       1 NEW                                               0        0 python
2024-08-09 14:21:15.191 E           TMP_ECP_RARE       2       2 NEW                                               0        0 python
2024-08-09 14:21:15.200 E           TMP_ECP_RARE       3       3 NEW                                               0        0 python
2024-08-09 14:21:15.207 E           TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
2024-08-09 14:21:15.215 E           TMP_ECP_RARE       4       5 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.220 E           TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.227 E           TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.235 E           TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
2024-08-09 14:21:15.241 E           TMP_ECP_RARE       1       9 BYE                                               0        0 python
2024-08-09 14:21:15.246 E           TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
2024-08-09 14:21:15.250 E           TMP_ECP_RARE       5      11 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.255 E           TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.260 E           TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.269 E           TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
2024-08-09 14:21:15.274 E           TMP_ECP_RARE       2      15 BYE                                               0        0 python
2024-08-09 14:21:15.281 E           TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
2024-08-09 14:21:15.286 E           TMP_ECP_RARE       6      17 RUN DML                                           0        0 firebird
2024-08-09 14:21:15.296 E           TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
2024-08-09 14:21:15.305 E           TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
2024-08-09 14:21:15.311 E           TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
2024-08-09 14:21:15.316 E           TMP_ECP_RARE       3      21 BYE                                               0        0 python
2024-08-09 14:21:15.324
2024-08-09 14:21:15.333 tests/functional/session/test_ext_conn_pool_01.py:391: AssertionError
2024-08-09 14:21:15.339 ---------------------------- Captured stdout setup -----------------------------
2024-08-09 14:21:15.344 Creating db: localhost:/var/tmp/qa_2024/test_12082/test.fdb [page_size=None, sql_dialect=None, charset='NONE', user=SYSDBA, password=masterkey]
2024-08-09 14:21:15.349 CREATE user: TMP_ECP_FREQ PLUGIN: Srp
2024-08-09 14:21:15.353 CREATE user: TMP_ECP_RARE PLUGIN: Srp
2024-08-09 14:21:15.358 CREATE role: CLEANER_EXT_POOL
2024-08-09 14:21:15.363 --------------------------- Captured stdout teardown ---------------------------
2024-08-09 14:21:15.368 DROP role: CLEANER_EXT_POOL
2024-08-09 14:21:15.377 DROP user: TMP_ECP_RARE PLUGIN: Srp
2024-08-09 14:21:15.382 DROP user: TMP_ECP_FREQ PLUGIN: Srp
3 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>
tmp_user_freq = <firebird.qa.plugin.User pytest object at [hex]>
tmp_user_rare = <firebird.qa.plugin.User pytest object at [hex]>
tmp_cleaner_role = <firebird.qa.plugin.Role pytest object at [hex]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.es_eds
    @pytest.mark.version('>=4.0')
    def test_1(act: Action, tmp_user_freq: User, tmp_user_rare: User, tmp_cleaner_role: Role, capsys):
    
        # [doc] state of external connections pool could be queried using ...:
        # - EXT_CONN_POOL_SIZE			pool size
        # - EXT_CONN_POOL_LIFETIME		idle connection lifetime, in seconds
        ECP_SIZE, ECP_LIFE = -1, -1
        with act.db.connect() as con:
            with con.cursor() as cur:
                cur.execute("select cast(rdb$get_context('SYSTEM', 'EXT_CONN_POOL_SIZE') as int), cast(rdb$get_context('SYSTEM', 'EXT_CONN_POOL_LIFETIME') as int) from rdb$database")
                ECP_SIZE, ECP_LIFE = cur.fetchone()
        assert ECP_SIZE > 1;
    
        SERVER_MODE = act.get_server_architecture()
        sql_init = f'''
            set bail on;
            set list on;
            set wng off;
            alter database set linger to {ECP_LIFE+ADD_DELAY_FOR_RARE+2};
            alter role {tmp_cleaner_role.name} set system privileges to MODIFY_EXT_CONN_POOL;
            commit;
    
            grant default {tmp_cleaner_role.name} to user {tmp_user_freq.name};
            grant default {tmp_cleaner_role.name} to user {tmp_user_rare.name};
            commit;
    
            set term ^;
            create function fn_get_bin_name() returns varchar(255) as
                declare v_bin_name varchar(255);
            begin
                v_bin_name = rdb$get_context('SYSTEM','CLIENT_PROCESS');
    
                -- ::: NOTE ::: Python binary can have numeric suffixes on Linux:
                if (v_bin_name similar to '%((\\python([[:DIGIT:]]+%)?.exe)|(/python([[:DIGIT:]]+%)?))') then
                    return 'python'; -- '/usr/bin/python3.9' ==> 'python'
    
                if (v_bin_name similar to '%((\\firebird([[:DIGIT:]]+%)?.exe)|(/python([[:DIGIT:]]+%)?))') then
                    return 'firebird';
    
                -- Extracts file name from full path of client binary process.
                -- For Windows: removes extension, in order returning name be the same as on Linux.
                -- 'c:\\program files\\firebird30\\firebird.exe' --> 'firebird'
                -- '/opt/firebird/bin/firebird'                  --> 'firebird'
                -- ::: NOTE ::: backslash must be duplicated when using this DDL in any Python
                -- environment otherwise it will be swallowed
                return
                (
                    select
                        --p
                        --,r
                        --,ext_pos
                        --,n
                        --,x
                        reverse(left(x,n)) as clnt_bin
                        -- reverse(x)  as clnt_bin
                    from
                    (
                        select
                            p
                            ,reverse(p) r
                            ,ext_pos
                            ,substring(reverse(p) from iif( is_win, ext_pos+1, 1) ) x
                            ,position( '|' in replace(replace(reverse( p ),'\\','|'),'/','|') ) - iif(is_win, ext_pos+1, 1) as n
                        from (
                            select
                                trim(p) as p
                                ,position( '\\' in p ) > 0 as is_win
                                ,iif( position( '\\' in p ) > 0, position('.' in reverse(trim(p))), 0) as ext_pos
                            from (
                                select rdb$get_context('SYSTEM','CLIENT_PROCESS') as p from rdb$database
                            )
                        )
                    )
                );
    
            end
            ^
            set term ;^
    
    
            create table ecp_audit(
                 id smallint generated by default as identity constraint pk_audit primary key
                ,srvmode varchar(12) -- 'Super' / 'SuperClassic' / 'Classic'
                ,who varchar(12) default current_user -- 'TMP_ECP_FREQ' / 'TMP_ECP_RARE' / 'SYSDBA'
                ,evt varchar(40) not null
                ,att smallint default current_connection
                ,trn smallint default current_transaction
                ,dts timestamp default 'now'
                ,pool_active_count smallint
                ,pool_idle_count smallint
                ,clnt_bin varchar(8)
                ,aux_info varchar(100)
            );
    
            create view v_ecp_audit as
            select
                who
               ,att
               ,id
               ,evt
               ,active_cnt
               ,idle_cnt
               ,clnt_bin
            from (
                select
                     srvmode
                    ,who
                    ,cast(dense_rank()over(partition by who order by att) as smallint) as att
                    ,cast(dense_rank()over(partition by who order by id) as smallint) as id
                    ,evt
                    ,trn
                    ,pool_active_count as active_cnt
                    ,pool_idle_count as idle_cnt
                    ,clnt_bin
                from ecp_audit
            )
            order by who, id
            ;
    
    
            grant select,insert on ecp_audit to public;
            grant select on v_ecp_audit to public;
            commit;
    
            set term ^;
            create or alter trigger trg_aud_bi for ecp_audit active before insert sql security definer as
                declare v_srvmode varchar(30);
                declare p int;
            begin
                new.srvmode = '{SERVER_MODE}';
                new.pool_active_count = rdb$get_context('SYSTEM','EXT_CONN_POOL_ACTIVE_COUNT');
                new.pool_idle_count = rdb$get_context('SYSTEM','EXT_CONN_POOL_IDLE_COUNT');
                new.clnt_bin = right(fn_get_bin_name(), 8);
                -- right(rdb$get_context('SYSTEM','CLIENT_PROCESS'),15);
            end
            ^
    
            create or alter trigger trg_connect inactive on connect sql security definer as
                declare p smallint;
            begin
                if (current_user <> '{act.db.user}') then
                begin
    
                    insert into ecp_audit(
                        evt
                    ) values (
                        iif(resetting, 'TAKE FROM POOL: IDLE -> ACTIVE', 'NEW')
                    );
                end
            end
            ^
    
            create or alter trigger trg_disconnect inactive on disconnect sql security definer as
            begin
                if (current_user <> '{act.db.user}') then
                begin
                    insert into ecp_audit(
                        evt
                    ) values (
                        iif(resetting, 'MOVE INTO POOL: ACTIVE -> IDLE', 'BYE')
                    );
                end
            end
            ^
            set term ;^
            commit;
            alter trigger trg_connect active;
            alter trigger trg_disconnect active;
            commit;
        '''
    
        act.expected_stdout = ''
        act.isql(switches = ['-q'], input = sql_init, combine_output = True, io_enc = locale.getpreferredencoding())
        assert act.clean_stdout == act.clean_expected_stdout
        act.reset()
    
        #-----------------------------------------------------
    
        sql_for_run = '''
            execute block as
                declare c int;
            begin
                execute statement ( q'{ insert into ecp_audit( evt ) values( 'RUN DML') }' )
                on external
                   'localhost:' || rdb$get_context('SYSTEM','DB_NAME')
                with autonomous transaction -- <<< !!! THIS IS MANDATORY IF WE WANT TO USE EXT CONN POOL !!! <<<
                as user current_user password '123'
                ;
            end
        '''
    
        for usr in (tmp_user_freq, tmp_user_rare):
            conn_list = []
            for i in range(0, ITER_LOOP_CNT):
                conn_list.append( act.db.connect(user = usr.name, password = usr.password) )
    
            for i,c in enumerate(conn_list):
    
                # ::: NOTE :::
                # ::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
                # On every iteration DIFFERENT connection is used for run ES/EDS,
                # but all of them use the same user/password/role, so apropriate
                # item in the ExtConnPool can be used to run this statement.
                # But this will be so only for user = 'FREQ' because he does such
                # actions 'frequently': each (<ECP_LIFE> - 2) seconds.
                # For user 'RARE' new attachment will be created every time when
                # he runs ES/EDS because he does that 'rarely' and idle connection
                # (from his previous iteration) is removed from ExtConnPool due to
                # expiration of ExtConnPoolLifeTime:
                # ::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
                try:
                    #c.execute_immediate( sql_for_run )
                    with c.cursor() as cur:
                        cur.execute(sql_for_run)
    
                    if i < len(conn_list)-1:
                        time.sleep( 1 if usr == tmp_user_freq else ECP_LIFE + ADD_DELAY_FOR_RARE )
                    else:
                        c.execute_immediate( 'ALTER EXTERNAL CONNECTIONS POOL CLEAR ALL' )
                finally:
                    if c:
                        c.close()
    
        if SERVER_MODE == 'Classic':
            act.expected_stdout = """
                WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
                ============ ======= ======= ======================================== ========== ======== ========
                TMP_ECP_FREQ       1       1 NEW                                               0        0 python
                TMP_ECP_FREQ       2       2 NEW                                               0        0 python
                TMP_ECP_FREQ       3       3 NEW                                               0        0 python
                TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
                TMP_ECP_FREQ       4       5 RUN DML                                           0        0 firebird
                TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_FREQ       1       8 BYE                                               0        1 python
                TMP_ECP_FREQ       5       9 NEW                                               0        0 firebird
                TMP_ECP_FREQ       5      10 RUN DML                                           0        0 firebird
                TMP_ECP_FREQ       5      11 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_FREQ       5      12 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_FREQ       4      13 BYE                                               0        0 firebird
                TMP_ECP_FREQ       2      14 BYE                                               0        1 python
                TMP_ECP_FREQ       6      15 NEW                                               0        0 firebird
                TMP_ECP_FREQ       6      16 RUN DML                                           0        0 firebird
                TMP_ECP_FREQ       6      17 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_FREQ       6      18 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_FREQ       6      19 BYE                                               0        0 firebird
                TMP_ECP_FREQ       3      20 BYE                                               0        0 python
                TMP_ECP_FREQ       5      21 BYE                                               0        0 firebird
                TMP_ECP_RARE       1       1 NEW                                               0        0 python
                TMP_ECP_RARE       2       2 NEW                                               0        0 python
                TMP_ECP_RARE       3       3 NEW                                               0        0 python
                TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
                TMP_ECP_RARE       4       5 RUN DML                                           0        0 firebird
                TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
                TMP_ECP_RARE       1       9 BYE                                               0        0 python
                TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
                TMP_ECP_RARE       5      11 RUN DML                                           0        0 firebird
                TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
                TMP_ECP_RARE       2      15 BYE                                               0        0 python
                TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
                TMP_ECP_RARE       6      17 RUN DML                                           0        0 firebird
                TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
                TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
                TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
                TMP_ECP_RARE       3      21 BYE                                               0        0 python
            """
        else:
            act.expected_stdout = """
                WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
                ============ ======= ======= ======================================== ========== ======== ========
                TMP_ECP_FREQ       1       1 NEW                                               0        0 python
                TMP_ECP_FREQ       2       2 NEW                                               0        0 python
                TMP_ECP_FREQ       3       3 NEW                                               0        0 python
                TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
                TMP_ECP_FREQ       4       5 RUN DML                                           1        0 firebird
                TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_FREQ       1       8 BYE                                               0        1 python
                TMP_ECP_FREQ       4       9 RUN DML                                           1        0 firebird
                TMP_ECP_FREQ       4      10 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_FREQ       4      11 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_FREQ       2      12 BYE                                               0        1 python
                TMP_ECP_FREQ       4      13 RUN DML                                           1        0 firebird
                TMP_ECP_FREQ       4      14 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_FREQ       4      15 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_FREQ       4      16 BYE                                               0        0 firebird
                TMP_ECP_FREQ       3      17 BYE                                               0        0 python
                TMP_ECP_RARE       1       1 NEW                                               0        0 python
                TMP_ECP_RARE       2       2 NEW                                               0        0 python
                TMP_ECP_RARE       3       3 NEW                                               0        0 python
                TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
                TMP_ECP_RARE       4       5 RUN DML                                           1        0 firebird
                TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
                TMP_ECP_RARE       1       9 BYE                                               0        0 python
                TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
                TMP_ECP_RARE       5      11 RUN DML                                           1        0 firebird
                TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
                TMP_ECP_RARE       2      15 BYE                                               0        0 python
                TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
                TMP_ECP_RARE       6      17 RUN DML                                           1        0 firebird
                TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    1        0 firebird
                TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    1        0 firebird
                TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
                TMP_ECP_RARE       3      21 BYE                                               0        0 python
            """
        act.isql(switches = ['-q', '-pag', '999999'], input = 'select who,att,id,evt,active_cnt,idle_cnt,clnt_bin from v_ecp_audit;', combine_output = True, io_enc = locale.getpreferredencoding())
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           WHO              ATT      ID EVT                                      ACTIVE_CNT IDLE_CNT CLNT_BIN
E           ============ ======= ======= ======================================== ========== ======== ========
E           TMP_ECP_FREQ       1       1 NEW                                               0        0 python
E           TMP_ECP_FREQ       2       2 NEW                                               0        0 python
E           TMP_ECP_FREQ       3       3 NEW                                               0        0 python
E           TMP_ECP_FREQ       4       4 NEW                                               0        0 firebird
E           TMP_ECP_FREQ       4       5 RUN DML                                           0        0 firebird
E           TMP_ECP_FREQ       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E           TMP_ECP_FREQ       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E           TMP_ECP_FREQ       1       8 BYE                                               0        1 python
E         + TMP_ECP_FREQ       4       9 BYE                                               0        0 firebird
E         - TMP_ECP_FREQ       5       9 NEW                                               0        0 firebird
E         + TMP_ECP_FREQ       5      10 NEW                                               0        0 firebird
E         - TMP_ECP_FREQ       5      10 RUN DML                                           0        0 firebird
E         + TMP_ECP_FREQ       5      11 RUN DML                                           0        0 firebird
E         - TMP_ECP_FREQ       5      11 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E         + TMP_ECP_FREQ       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E         - TMP_ECP_FREQ       5      12 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E         + TMP_ECP_FREQ       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E         - TMP_ECP_FREQ       4      13 BYE                                               0        0 firebird
E           TMP_ECP_FREQ       2      14 BYE                                               0        1 python
E           TMP_ECP_FREQ       6      15 NEW                                               0        0 firebird
E           TMP_ECP_FREQ       6      16 RUN DML                                           0        0 firebird
E           TMP_ECP_FREQ       6      17 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E           TMP_ECP_FREQ       6      18 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E           TMP_ECP_FREQ       6      19 BYE                                               0        0 firebird
E         - TMP_ECP_FREQ       3      20 BYE                                               0        0 python
E         - TMP_ECP_FREQ       5      21 BYE                                               0        0 firebird
E         + TMP_ECP_FREQ       5      20 BYE                                               0        0 firebird
E         + TMP_ECP_FREQ       3      21 BYE                                               0        0 python
E           TMP_ECP_RARE       1       1 NEW                                               0        0 python
E           TMP_ECP_RARE       2       2 NEW                                               0        0 python
E           TMP_ECP_RARE       3       3 NEW                                               0        0 python
E           TMP_ECP_RARE       4       4 NEW                                               0        0 firebird
E           TMP_ECP_RARE       4       5 RUN DML                                           0        0 firebird
E           TMP_ECP_RARE       4       6 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E           TMP_ECP_RARE       4       7 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E           TMP_ECP_RARE       4       8 BYE                                               0        0 firebird
E           TMP_ECP_RARE       1       9 BYE                                               0        0 python
E           TMP_ECP_RARE       5      10 NEW                                               0        0 firebird
E           TMP_ECP_RARE       5      11 RUN DML                                           0        0 firebird
E           TMP_ECP_RARE       5      12 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E           TMP_ECP_RARE       5      13 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E           TMP_ECP_RARE       5      14 BYE                                               0        0 firebird
E           TMP_ECP_RARE       2      15 BYE                                               0        0 python
E           TMP_ECP_RARE       6      16 NEW                                               0        0 firebird
E           TMP_ECP_RARE       6      17 RUN DML                                           0        0 firebird
E           TMP_ECP_RARE       6      18 MOVE INTO POOL: ACTIVE -> IDLE                    0        0 firebird
E           TMP_ECP_RARE       6      19 TAKE FROM POOL: IDLE -> ACTIVE                    0        0 firebird
E           TMP_ECP_RARE       6      20 BYE                                               0        0 firebird
E           TMP_ECP_RARE       3      21 BYE                                               0        0 python

tests/functional/session/test_ext_conn_pool_01.py:391: AssertionError
Full history of outcomes and elapsed time, ms:
NN SNAP_INFO CS_outcome SS_outcome CS_run_time SS_run_time CS_run_beg CS_run_end SS_run_beg SS_run_end
1 4.0.6.3189 2025.02.25 1a1a5 P P 29331 27977 2025.06.29 16:05:44.861 2025.06.29 16:06:14.192 2025.06.29 14:50:22.895 2025.06.29 14:50:50.872
2 4.0.6.3184 2025.02.24 9388c P P 673 481 2025.02.25 14:01:58.864 2025.02.25 14:01:59.537 2025.02.25 12:40:58.639 2025.02.25 12:40:59.120
3 4.0.6.3183 2025.02.16 cf6ca P P 696 425 2025.02.17 07:56:18.520 2025.02.17 07:56:19.216 2025.02.17 06:34:36.855 2025.02.17 06:34:37.280
4 4.0.6.3169 2024.12.13 42cc1 P P 670 495 2025.02.16 04:53:07.277 2025.02.16 04:53:07.947 2025.02.16 03:33:38.981 2025.02.16 03:33:39.476
5 4.0.6.3169 2024.12.08 50eb6 P P 517 346 2024.12.12 19:08:02.782 2024.12.12 19:08:03.299 2024.12.12 18:04:10.483 2024.12.12 18:04:10.829
6 4.0.6.3168 2024.11.28 48149 P P 514 379 2024.12.06 03:27:40.986 2024.12.06 03:27:41.500 2024.12.06 02:26:05.707 2024.12.06 02:26:06.086
7 4.0.6.3163 2024.10.16 2bb10 P P 543 358 2024.11.27 13:52:40.649 2024.11.27 13:52:41.192 2024.11.27 10:49:45.636 2024.11.27 10:49:45.994
8 4.0.6.3163 2024.10.15 f387e P P 508 363 2024.10.16 04:57:41.467 2024.10.16 04:57:41.975 2024.10.16 03:58:36.721 2024.10.16 03:58:37.084
9 4.0.6.3147 2024.08.31 4655b P P 555 378 2024.09.30 12:14:34.086 2024.09.30 12:14:34.641 2024.09.30 11:08:33.407 2024.09.30 11:08:33.785
10 4.0.6.3140 2024.08.16 1dd8b P P 1022 669 2024.08.31 18:55:25.599 2024.08.31 18:55:26.621 2024.08.31 16:54:23.812 2024.08.31 16:54:24.481
11 4.0.6.3140 2024.08.09 34747 P P 653 477 2024.08.16 11:20:41.368 2024.08.16 11:20:42.021 2024.08.16 10:08:40.619 2024.08.16 10:08:41.096
12 4.0.5.3110 2024.07.30 c6527 F P 1083 484 2024.08.09 11:14:11.665 2024.08.09 11:14:12.748 2024.08.09 09:59:26.518 2024.08.09 09:59:27.002
13 4.0.5.3109 2024.06.11 6addf P P 483 275 2024.07.30 09:27:32.435 2024.07.30 09:27:32.918 2024.07.30 08:24:57.861 2024.07.30 08:24:58.136
14 4.0.5.3097 2024.05.09 27fa6 P P 637 513 2024.05.14 10:12:45.212 2024.05.14 10:12:45.849 2024.05.14 09:08:27.725 2024.05.14 09:08:28.238
15 4.0.5.3091 2024.04.29 bd0aa P P 372 244 2024.05.08 21:12:09.772 2024.05.08 21:12:10.144 2024.05.08 20:17:35.648 2024.05.08 20:17:35.892
16 4.0.5.3089 2024.04.25 4b9c7 P P 411 263 2024.04.27 15:56:45.756 2024.04.27 15:56:46.167 2024.04.27 15:01:26.164 2024.04.27 15:01:26.427

Elapsed time, ms. Chart for last 16 runs:

Last commits information (all timestamps in UTC):