Invocations of rdb$profiler.start_session / rdb$profiler.finish_session can cause valuable delay between script cancellation and appropriate server process completion

Suppose we have to run loop with lot iterations and do following within each iteration:

start profiler with some options
do some stuff
stop profiler

This can be illustrated by following simplified script (with infinite loop instead of some large limit):

execute block returns(x int) as
    declare use_profiler smallint = 1; -- [ ! ]

    declare dummy bigint;
    declare i smallint = 0;
begin
    while (i < 1) do
    begin
        if ( use_profiler = 1 ) then
            select rdb$profiler.start_session('prof_ssn_' || :i) from rdb$database into :dummy;

        select rdb$linger from rdb$database into dummy;

        -- rdb$set_context('USER_TRANSACTION', 'DEBUG_FOR_WATCH_IN_TRACE', current_time); --  #1
        -- suspend; -- #2

        if ( use_profiler = 1 ) then
            execute procedure rdb$profiler.finish_session(true);

        -- i = i + 1; -- #3
    end
end

Now let change firebird.conf by adding: StatementTimeout = 300

Restart service, run script (using ISQL) shown above and let it work at least 25 ... 30 seconds. Then let's cancel script by pressing Ctrl-Break.

File firebird.log at this moment will show time when we did cancellation:

PZ  Mon Jul 15 17:47:02 2024
INET/inet_error: read errno = 10054, client host = pz, address = ::1/62953, user = user

So far so good. But server process (firebird.exe) will NOT stop its work for valuable time, continuing to load one of CPU cores for ~100%. And this will last for StatementTimeout - <N> seconds, where <N> is about 18...20. During that time DB file remains opened. / Value of <N> can be evaluated quite precisely if we will wait until firebird process will finished and then get exact time of DB last_modified file attribute, e.g.: wmic datafile where name='R:\\Temp\\TMP4TEST.FDB' get LastModified /format:list | more /

If you change use_profiler to 0 (see line marked as "[ ! ]") then all became fine: firebird process will be eliminated after 1...2 seconds after script cancellation. Same if we uncomment any of lines marked as "#1", "#2" or "#3" (with use_profiler = 1).

PS. 6.0.0.395, config:

AuthServer = Srp, Win_Sspi, Legacy_Auth
BugCheckAbort = 1
ClearGTTAtRetaining = 0
ClientBatchBuffer = 131072
ConnectionIdleTimeout = 0
DefaultDBCachePages = 10K
ExtConnPoolLifeTime = 10
ExtConnPoolSize = 10
ExternalFileAccess = Full
InlineSortThreshold = 1000
IpcName = xnet_fb6x_ss
KeyHolderPlugin = fbSampleKeyHolder
MaxIdentifierByteLength = 252
MaxIdentifierCharLength = 63
MaxParallelWorkers = 8
MaxUnflushedWrites = -1
MaxUnflushedWriteTime = -1
ParallelWorkers = 1
ReadConsistency = 0
RemoteServicePort = 3600
ServerMode = Classic
SnapshotsMemSize = 64K
StatementTimeout = 300
TempCacheLimit = 1G
TipCacheBlockSize = 4M
UseFileSystemCache = true
UserManager = Srp, Legacy_UserManager
WireCrypt = Enabled
WireCryptPlugin = ChaCha, Arc4

FirebirdSQL / firebird

Invocations of rdb$profiler.start_session / rdb$profiler.finish_session can cause valuable delay between script cancellation and appropriate server process completion #8183