ERROR: connection shutdown (in replication.log)

[Dany40]

Hello,

We have 5 replica servers, with arround 95 dababses on each. They are all Firebird 32 bit version 4.0.3. Time to time we found the Firebird service runninb, but replication stopped, and this list of errors on the replication.log:

REPLICA Mon Dec  4 13:07:42 2023
Database: E:\SLAVE\NUBE\30911332.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:07:42 2023
Database: E:\SLAVE\NUBE\36521069.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:07:45 2023
Database: E:\SLAVE\NUBE\22854374.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:07:51 2023
Database: E:\SLAVE\NUBE\18906117.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:07:53 2023
Database: E:\SLAVE\NUBE\00000419.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:08:31 2023
Database: E:\SLAVE\NUBE\48905395.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:08:46 2023
Database: E:\SLAVE\NUBE\88384056.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:10:15 2023
Database: E:\SLAVE\NUBE\24785325.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:10:42 2023
Database: E:\SLAVE\NUBE\26100632.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:11:44 2023
Database: E:\SLAVE\NUBE\46005328.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:11:45 2023
Database: E:\SLAVE\NUBE\78189407.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:12:03 2023
Database: E:\SLAVE\NUBE\23736006.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:13:13 2023
Database: E:\SLAVE\NUBE\59364072.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:13:53 2023
Database: E:\SLAVE\NUBE\27026632.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:14:02 2023
Database: E:\SLAVE\NUBE\42446733.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:14:23 2023
Database: E:\SLAVE\NUBE\51723345.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:15:44 2023
Database: E:\SLAVE\NUBE\39400915.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:16:54 2023
Database: E:\SLAVE\NUBE\93147704.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:17:02 2023
Database: E:\SLAVE\NUBE\76261474.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:17:54 2023
Database: E:\SLAVE\NUBE\27064337.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:19:13 2023
Database: E:\SLAVE\NUBE\81348570.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:19:26 2023
Database: E:\SLAVE\NUBE\28295597.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:19:32 2023
Database: E:\SLAVE\NUBE\11289358.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:21:02 2023
Database: E:\SLAVE\NUBE\25321983.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:22:32 2023
Database: E:\SLAVE\NUBE\82276292.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:24:34 2023
Database: E:\SLAVE\NUBE\56926458.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:25:13 2023
Database: E:\SLAVE\NUBE\39086957.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:28:02 2023
Database: E:\SLAVE\NUBE\09208758.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:32:34 2023
Database: E:\SLAVE\NUBE\63137564.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:32:54 2023
Database: E:\SLAVE\NUBE\17460213.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:39:53 2023
Database: E:\SLAVE\NUBE\25876781.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:40:53 2023
Database: E:\SLAVE\NUBE\23162796.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:42:24 2023
Database: E:\SLAVE\NUBE\29082277.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:46:54 2023
Database: E:\SLAVE\NUBE\33467319.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:50:04 2023
Database: E:\SLAVE\NUBE\35869670.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:50:04 2023
Database: E:\SLAVE\NUBE\34753702.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:51:04 2023
Database: E:\SLAVE\NUBE\55186100.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:51:04 2023
Database: E:\SLAVE\NUBE\60267325.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:52:14 2023
Database: E:\SLAVE\NUBE\35927503.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 13:59:25 2023
Database: E:\SLAVE\NUBE\23369096.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:00:15 2023
Database: E:\SLAVE\NUBE\08666518.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:09:37 2023
Database: E:\SLAVE\NUBE\40085484.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:12:36 2023
Database: E:\SLAVE\NUBE\87862901.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:15:05 2023
Database: E:\SLAVE\NUBE\85337778.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:15:18 2023
Database: E:\SLAVE\NUBE\21389051.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:17:25 2023
Database: E:\SLAVE\NUBE\93108757.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:22:37 2023
Database: E:\SLAVE\NUBE\63823384.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:22:38 2023
Database: E:\SLAVE\NUBE\01403257.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 14:28:36 2023
Database: E:\SLAVE\NUBE\90107629.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:03:09 2023
Database: E:\SLAVE\NUBE\46632565.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:14:10 2023
Database: E:\SLAVE\NUBE\00124210.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:14:49 2023
Database: E:\SLAVE\NUBE\10154894.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:18:19 2023
Database: E:\SLAVE\NUBE\61222101.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:19:19 2023
Database: E:\SLAVE\NUBE\41340714.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:27:30 2023
Database: E:\SLAVE\NUBE\21708441.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:41:31 2023
Database: E:\SLAVE\NUBE\23661734.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 15:54:22 2023
Database: E:\SLAVE\NUBE\83060778.FDB
ERROR: connection shutdown

REPLICA Mon Dec  4 16:32:36 2023
Database: E:\SLAVE\NUBE\21161474.FDB
ERROR: connection shutdown

By restarting the Firebird service, all the segments are procesed in normal way, no errors. We cannot find the source of this problem. What can it be?

Thank you!

[Vlad Khorsun]

We have 5 replica servers, with arround 95 dababses on each. They are all Firebird 32 bit version 4.0.3. Time to time we found the Firebird service runninb, but replication stopped, and this list of errors on the replication.log:

  How do you know replication is stopped ? By design, it should continue after some pause (60 sec by default).

And I see no repeated messages for the same database.

 

REPLICA Mon Dec  4 13:07:42 2023
Database: E:\SLAVE\NUBE\30911332.FDB
ERROR: connection shutdown

...

 

By restarting the Firebird service, all the segments are procesed in normal way, no errors. We cannot find the source of this problem. What can it be?

  Hard to say with existing information. 

Any interesting messages at firebird.log ? 

What user activity happens on replica database(s) that could shutdown replication connection ?

Could someone kill it (using monitoring, for example) ?

 

Regards,

Vlad

PS I still waiting for you answer at https://github.com/FirebirdSQL/firebird/issues/7684

[Dany40]

I know the replication is stopped because there are a lot of segments unreaded. In the moment I restart the Firebird service, it needs less than one minute for reading saving and deleting all that segments.

There are no news on the firebird.log.

Each replication machine is only for replication, in where only one Firebird service instance  is running and is the only one using the replica databases.
About the issue 7684, we never found problems like that again.

Thank you!

[Vlad Khorsun]

I know the replication is stopped because there are a lot of segments unreaded. In the moment I restart the Firebird service, it needs less than one minute for reading saving and deleting all that segments.

There are no news on the firebird.log.

Each replication machine is only for replication, in where only one Firebird service instance  is running and is the only one using the replica databases.

  It is not a expected and need some investigations. As a very first step, I'd recommend to allow 'verbose_logging' for at least one instance and watch 

for replication.log regularly on this instance. It could grow fast, so be careful. Probably it would make sense to enlarge 'apply_idle_timeout' also. 

Next, I would like to look at full memory dump of such "hung' Firebird process - right before service restart. Watch for memory usage also - as you 

use 32-bit process that handle many databases. BTW, I see no good reason to use 32-bit Firebird on replicas, I remember you use 32-bit Firebird 

because of user's HW and/or OS, but is it a case for replica servers too ?

Regards,

Vlad

[Dany40]

Thank you Vlad. I will go with your suggestions trying to come back with new information.

[Dany40]

Hi Vlad; I  have the dump file but when I attach it, I can publish the message as it is too long. Where can I send it?. At the time I build the dump file, the Firebird service was processing the replication segments, but not for all the databases (4 or 5 databases not, but the others 90 aprox yes).

After doing the dump, I restarted the Firebird service and then all the segmente where processed, for the 100% of the databases.

Thank you!

[Dany40]

Hi Vlad; Please can you remember me if you received the dump file and if you found something relevant on it?. (Very sorry for asking long time before, on 13 dic 2023 I entered in a big brain surgery and then I forget this thread, but it is important because I still get this kind of errors on 64 bit 4.0.5).

Regards!

[Vlad Khorsun]

Hi Vlad; Please can you remember me if you received the dump file and if you found something relevant on it?. (Very sorry for asking long time before, on 13 dic 2023 I entered in a big brain surgery and then I forget this thread, but it is important because I still get this kind of errors on 64 bit 4.0.5).

  Hope you are fine after the surgery, sad to hear about it.

I didn't find mail from you at Dec 2023, so I guess it was not sent.

Regards,

Vlad

[Dany40]

Thank you Vlad, and I am fine now, thank you.
I will try to build a new DUMP file. It is a very strange problem, as we have 5 machines with MS-Windows 11 to receive replication; in the 5 we have Firebird 4.0.5 64 bits as a service, which is the only one interacting with the databases. In the 5 machines we are founding the same problem. In all the cases, by restarting Firebird, replication starts to work again.

Regards,

Dany

[Dany40]

Hello Vlad;

Here you have a zip file with a dump for the 64 bit Firebird server version 4.0.5.3100 when it does the  "connection shutdown" error.

https://drive.google.com/file/d/1U-xwS86d8MQIfj3zdYgffP-e8nk2sIIJ/view?usp=sharing

To help you remember: We have 6 computers with Windows 11 PRO installations on which Firebird servers runs to receive replicas. This error occurs every now and then on any of those servers. In the 6 computers, the installed Firebird is the same 4.0.5.3100 now but previous versions also produced this error.

Thank you and best regards.

[Vlad Khorsun]

Hello Dany,

Here you have a zip file with a dump for the 64 bit Firebird server version 4.0.5.3100 when it does the  "connection shutdown" error.

https://drive.google.com/file/d/1U-xwS86d8MQIfj3zdYgffP-e8nk2sIIJ/view?usp=sharing

  Version 4.0.5.3100 is a snapshot build from 15.05.2024. Debug info (.pdb files) of that build is required to read and analyze the 

memory dump. Without .pdb files it is useless, sorry. 

  Next. I already asked you to turn on verbose_logging but it seems you didn't do it, as replication.log still contains just a few of 

"ERROR: connection shutdown" messages.

  Please, install *released* version of Firebird (https://www.firebirdsql.org/en/firebird-4-0-5/) and enable verbose logging in replication.conf.

Regards,

Vlad

[Dany40]

Thank you Vlad. We have 4.0.5.3100 in both sides (master and replica); do you think we can update our replica side only without side efects?.

BTW, I can send you the PDB file for  4.0.5.3100 if it helps, let me know please.

[Vlad Khorsun]

Thank you Vlad. We have 4.0.5.3100 in both sides (master and replica); do you think we can update our replica side only without side efects?.

  Should be OK. Note, there was at least one bug fixed before 4.0.5 release that affects master (#8138)

 

BTW, I can send you the PDB file for  4.0.5.3100 if it helps, let me know please.

  Yes, send a link to me, maybe we are lucky and it allows to find the reason. But anyway upgrade to the released version 

and turn verbose_logging on.

Regards,

Vlad

[Dany40]

Hello Vlad;

Here you can download the Firebird 4.0.5.3100 snapshot:

https://drive.google.com/file/d/1nrU8oPz4znkxzWAtl0SpQp0v-EkjCAKH/view?usp=sharing

Regards!

[Vlad Khorsun]

Hello Vlad;

Here you can download the Firebird 4.0.5.3100 snapshot:

 

  Good, now I can analyze the memory dump. And I see a lot of replicator threads (one per replica database)

that is idle waiting for new segments arrival. Probably, when they wake up and handle segments (you tald that 

segments are present) some error or other event happens but we have no idea about it as verbose logging is

not enabled. Please, enable verbose logging and it could help us to understand why segments are not handled.

  Also, check if databases that mentioned in replication.log is online (gstat -h)

Regards,

Vlad