From time to time handle to restore of security3.fdb backup is not released by firebird.exe (using service_mgr) [CORE6082]

[firebird-automations]

Submitted by: @livius2

Attachments:
FirebirdHandle.png
MonAtt.png
Current_MonAtt.png
MonTransactions.png
MonAttAfterNoLinger.png
SomeAdditionalInfo.txt

We have automatic backup and restore process of many databases including security3.fdb
But from time to time - and only for "security3.fdb.restored", file handle is not released by firebird.exe and cannot be deleted.

gbak: time delta
gbak: 0.000 0.000 opened file D:\backup\security3.bak
gbak: ERROR:database D:\restore\security3.fdb.restored already exists. To replace it, use the -REP switch
gbak: ERROR: Exiting before completion due to errors
gbak:Exiting before completion due to errors

the process looks like this:
1. We try to delete previous files (we do not check if this process is succesfull or not)
2. every night we run backup to "security3.bak"
we validate the succesfull by "looking" into log file for text "closing file, committing, and finishing" if not present, we write log and also send email to admins
3. next we run restore process and this is also validated by log like in point 2.
all was ok and next day process failed on steep 3 as in step 1 security3.fdb.restored was not deleted.

We try to delete it but it is looked by the firebird.exe and never released - we have waited few days previously, now it is 1 day, as visible in MON$ATTACHMENT.
restore command looks like
"%FB_DIR%\gbak" -service 127.0.0.1:service_mgr -c -v -BUFFERS 131072 -STATISTICS TD -user SYSDBA -password XXXX %FB_BACKUP%\security3.bak %FB_RESTORE%\security3.fdb.restored

i can connect to this restored database (screen from MON$ATTACHMENT added) but only way to free handle to file is to stop Firebird server.

This situation have occured 3 times - and now we report this here.

[firebird-automations]

Commented by: @livius2

View from "Resource monitor"

[firebird-automations]

Modified by: @livius2

Attachment: FirebirdHandle.png [ 13354 ]

[firebird-automations]

Modified by: @livius2

Attachment: MonAtt.png [ 13355 ]

[firebird-automations]

Modified by: @livius2

description: We have automatic backup and restore process of many databases including security3.fdb
But from time to time - and only for "security3.fdb.restored", file handle is not released by firebird.exe and cannot be deleted.

gbak: time delta
gbak: 0.000 0.000 opened file D:\backup\security3.bak
gbak: ERROR:database D:\restore\security3.fdb.restored already exists. To replace it, use the -REP switch
gbak: ERROR: Exiting before completion due to errors
gbak:Exiting before completion due to errors

the process looks like this:
1. We try to delete previous files (we do not check if this process is succesfull or not)
2. every night we run backup to "security3.bak"
we validate the succesfull by "looking" into log file for text "closing file, committing, and finishing" if not present, we write log and also send email to admins
3. next we run restore process and this is also validated by log like in point 2.
all was ok and next day process failed on steep 3 as in step 1 security3.fdb.restored was not deleted.

We try to delete it but it is looked by the firebird.exe and never released - we have waited few days.
restore command looks like
"%FB_DIR%\gbak" -service 127.0.0.1:service_mgr -c -v -BUFFERS 131072 -STATISTICS TD -user SYSDBA -password XXXX %FB_BACKUP%\security3.bak %FB_RESTORE%\security3.fdb.restored

This situation have occured 3 times - and now we report this here.

=>

We have automatic backup and restore process of many databases including security3.fdb
But from time to time - and only for "security3.fdb.restored", file handle is not released by firebird.exe and cannot be deleted.

gbak: time delta
gbak: 0.000 0.000 opened file D:\backup\security3.bak
gbak: ERROR:database D:\restore\security3.fdb.restored already exists. To replace it, use the -REP switch
gbak: ERROR: Exiting before completion due to errors
gbak:Exiting before completion due to errors

the process looks like this:
1. We try to delete previous files (we do not check if this process is succesfull or not)
2. every night we run backup to "security3.bak"
we validate the succesfull by "looking" into log file for text "closing file, committing, and finishing" if not present, we write log and also send email to admins
3. next we run restore process and this is also validated by log like in point 2.
all was ok and next day process failed on steep 3 as in step 1 security3.fdb.restored was not deleted.

We try to delete it but it is looked by the firebird.exe and never released - we have waited few days.
restore command looks like
"%FB_DIR%\gbak" -service 127.0.0.1:service_mgr -c -v -BUFFERS 131072 -STATISTICS TD -user SYSDBA -password XXXX %FB_BACKUP%\security3.bak %FB_RESTORE%\security3.fdb.restored

i can connect to this restored database (screen from MON$ATTACHMENT added) but only way to free handle to file is to stop Firebird server.

This situation have occured 3 times - and now we report this here.

[firebird-automations]

Modified by: @livius2

description: We have automatic backup and restore process of many databases including security3.fdb
But from time to time - and only for "security3.fdb.restored", file handle is not released by firebird.exe and cannot be deleted.

gbak: time delta
gbak: 0.000 0.000 opened file D:\backup\security3.bak
gbak: ERROR:database D:\restore\security3.fdb.restored already exists. To replace it, use the -REP switch
gbak: ERROR: Exiting before completion due to errors
gbak:Exiting before completion due to errors

the process looks like this:
1. We try to delete previous files (we do not check if this process is succesfull or not)
2. every night we run backup to "security3.bak"
we validate the succesfull by "looking" into log file for text "closing file, committing, and finishing" if not present, we write log and also send email to admins
3. next we run restore process and this is also validated by log like in point 2.
all was ok and next day process failed on steep 3 as in step 1 security3.fdb.restored was not deleted.

We try to delete it but it is looked by the firebird.exe and never released - we have waited few days.
restore command looks like
"%FB_DIR%\gbak" -service 127.0.0.1:service_mgr -c -v -BUFFERS 131072 -STATISTICS TD -user SYSDBA -password XXXX %FB_BACKUP%\security3.bak %FB_RESTORE%\security3.fdb.restored

i can connect to this restored database (screen from MON$ATTACHMENT added) but only way to free handle to file is to stop Firebird server.

This situation have occured 3 times - and now we report this here.

=>

We have automatic backup and restore process of many databases including security3.fdb
But from time to time - and only for "security3.fdb.restored", file handle is not released by firebird.exe and cannot be deleted.

gbak: time delta
gbak: 0.000 0.000 opened file D:\backup\security3.bak
gbak: ERROR:database D:\restore\security3.fdb.restored already exists. To replace it, use the -REP switch
gbak: ERROR: Exiting before completion due to errors
gbak:Exiting before completion due to errors

the process looks like this:
1. We try to delete previous files (we do not check if this process is succesfull or not)
2. every night we run backup to "security3.bak"
we validate the succesfull by "looking" into log file for text "closing file, committing, and finishing" if not present, we write log and also send email to admins
3. next we run restore process and this is also validated by log like in point 2.
all was ok and next day process failed on steep 3 as in step 1 security3.fdb.restored was not deleted.

We try to delete it but it is looked by the firebird.exe and never released - we have waited few days previously, now it is 1 day, as visible in MON$ATTACHMENT.
restore command looks like
"%FB_DIR%\gbak" -service 127.0.0.1:service_mgr -c -v -BUFFERS 131072 -STATISTICS TD -user SYSDBA -password XXXX %FB_BACKUP%\security3.bak %FB_RESTORE%\security3.fdb.restored

i can connect to this restored database (screen from MON$ATTACHMENT added) but only way to free handle to file is to stop Firebird server.

This situation have occured 3 times - and now we report this here.

[firebird-automations]

Modified by: @AlexPeshkoff

assignee: Alexander Peshkov [ alexpeshkoff ]

[firebird-automations]

Commented by: @AlexPeshkoff

I can see only one difference between security database and other DBs - it has by default non-zero linger. Is is set on your sec/db?

[firebird-automations]

Commented by: @livius2

I do not change linger for restored db, but i suppose it is default in minutes not days?

[firebird-automations]

Commented by: @AlexPeshkoff

It's not in minutes, it's seconds :)

I asked cause I want to have some idea from where to start. IMO some bug is present here but you see yourself - when we talk about something that happened for you 3 times it's rather hard to fix something using just this info. We need a way to reproduce soemthing. BTW, 3 failures per how many successful restores?

[firebird-automations]

Commented by: @livius2

Yes, i know. Without reproducible test case it is hard to start.

We have 3 failtures in this year. The job start at every night and we have now day 164 of the year.
Then most of the time it is working without problem.

[firebird-automations]

Commented by: @livius2

I have tried
1.
database sweep - manually
2.
delete from MON$ATTACHMENTS WHERE MON$USER<>'SYSDBA'

--- no success or any change --
3.
gfix -nolinger
above change something as garbage collector and cache writer are finished and when i have connect to database it show current dates

But still Firebird do not release handle to the file :(

[firebird-automations]

Modified by: @livius2

Attachment: Current_MonAtt.png [ 13356 ]

Attachment: MonTransactions.png [ 13357 ]

[firebird-automations]

Modified by: @livius2

Attachment: MonAttAfterNoLinger.png [ 13358 ]

[firebird-automations]

Modified by: @livius2

Attachment: SomeAdditionalInfo.txt [ 13359 ]

[firebird-automations]

Commented by: @livius2

I have found the way how to fix this. I should do this at start, but as you can see i must run this command 2 times to work
First try show an error as db is bining used.
Second try do not show this message and show error about permission (i do not provide user and password)
Third try work ok, Firebird release handle and i have deleted database file :)
---------------------------------------------------------------------------------------------------------------------------------------
C:\Firebird>gfix -shutdown -force 1 D:\restore\SECURITY3.FDB.RESTORED
I/O error during "CreateFile (open)" operation for file "D:\RESTORE\SECURITY3.FDB.RESTORED"
-Error while trying to open file
-The process cannot access the file because it is being used by another process.

---------------------------------------------------------------------------------------------------------------------------------------

C:\Firebird>gfix -shutdown -force 1 D:\restore\SECURITY3.FDB.RESTORED
no permission for shutdown access to database D:\RESTORE\SECURITY3.FDB.RESTORED

---------------------------------------------------------------------------------------------------------------------------------------

C:\Firebird>gfix -shutdown -force 1 -user sysdba -password XXXXXXX D:\restore\SECURITY3.FDB.RESTORED

C:\Firebird>