I have a backup dedicated server (Debian 9) with Bacula and OpenVPN tunnel to the main server (Ubuntu 18.04) from which I collect data for backups using Bacula File Daemon. I had successfully working configuration. But a few days ago I encountered an issue. Bacula Storage daemon hangs up after transferring several packets while backing up large file sets. In status section of Bacula console it seems like hanging up on random file processing. After that packet transmission between Storage daemon and remote File daemon become interrupted. Bacula versions on the servers are the same. The error log is following:
16-июл 15:47 gitlab-ci-dir JobId 2254: Max Volume jobs=1 exceeded. Marking Volume "RCER_-0580" as Used.
16-июл 16:03 robotics-fd JobId 2254: Error: bsock.c:383 Write error sending 16399 bytes to Storage daemon:10.8.0.2:9103: ERR=Connection timed out
16-июл 16:03 robotics-fd JobId 2254: Fatal error: backup.c:843 Network send error to SD. ERR=Connection timed out
16-июл 16:03 robotics-fd JobId 2254: Error: bsock.c:271 Socket has errors=1 on call to Storage daemon:10.8.0.2:9103
16-июл 16:03 gitlab-ci-storage JobId 2254: Error: bsock.c:551 Read error from client:10.8.0.1:49200: ERR=Interrupted system call
16-июл 16:03 gitlab-ci-dir JobId 2254: Error: Bacula gitlab-ci-dir 9.4.2 (04Feb19):
Build OS: x86_64-pc-linux-gnu debian 9.6
JobId: 2254
******************************
Elapsed time: 16 mins
Priority: 10
FD Files Written: 1,680
SD Files Written: 0
FD Bytes Written: 10,438,504 (10.43 MB)
SD Bytes Written: 0 (0 B)
Rate: 10.9 KB/s
Software Compression: 100.0% 1.0:1
Comm Line Compression: None
Snapshot/VSS: no
Encryption: no
Accurate: no
Volume name(s):
Volume Session Id: 7
Volume Session Time: 1563276316
Last Volume Bytes: 248 (248 B)
Non-fatal FD errors: 2
SD Errors: 0
FD termination status: Error
SD termination status: Running
Termination: *** Backup Error ***
On netstat it seems like File daemon interrupts transfer of packets to Storage daemon and after several tries it hangs up:
17:00:54.458254 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115274004:115275350, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458260 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115275350:115276696, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458261 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115276696:115278042, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458262 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115278042:115279388, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458262 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115279388:115280734, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458263 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115280734:115282080, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458264 IP robotics.59654 > 10.8.0.2.bacula-sd: Flags [.], seq 115282080:115283426, ack 178, win 115, options [nop,nop,TS val 11940365 ecr 2393171], length 1346
17:00:54.458495 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115135366, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.458883 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115138058, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.459005 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115140750, win 6919, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.459142 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115143442, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.459337 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115146134, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.459580 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115148826, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.459838 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115151518, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.460093 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115154210, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.460273 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115156902, win 6928, options [nop,nop,TS val 2393171 ecr 11940356], length 0
17:00:54.460572 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115159594, win 6928, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.460735 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115162286, win 6928, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.461046 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115164978, win 6928, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.461219 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115167670, win 6928, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.461497 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115170362, win 6928, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.461794 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115173054, win 6923, options [nop,nop,TS val 2393172 ecr 11940356], length 0
17:00:54.461938 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115175746, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.462238 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115178438, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.462432 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115181130, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.462694 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115183822, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.463149 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115186514, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.463258 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115189206, win 6923, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.463410 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115191898, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.463687 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115194590, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.463964 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115197282, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.464136 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393172 ecr 11940357], length 0
17:00:54.464287 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393172 ecr 11940357,nop,nop,sack 1 {115239008:115240354}], length 0
17:00:54.464436 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115241700}], length 0
17:00:54.465026 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115243046}], length 0
17:00:54.465075 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115244392}], length 0
17:00:54.465095 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115245738}], length 0
17:00:54.465247 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115247084}], length 0
17:00:54.465414 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115248430}], length 0
17:00:54.465575 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115249776}], length 0
17:00:54.465751 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115251122}], length 0
17:00:54.465784 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115252468}], length 0
17:00:54.465800 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115253814}], length 0
17:00:54.465925 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115255160}], length 0
17:00:54.466080 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115256506}], length 0
17:00:54.466151 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115257852}], length 0
17:00:54.466290 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115259198}], length 0
17:00:54.466398 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115260544}], length 0
17:00:54.466525 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115261890}], length 0
17:00:54.466647 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115263236}], length 0
17:00:54.466780 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115264582}], length 0
17:00:54.466931 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115265928}], length 0
17:00:54.467107 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115267274}], length 0
17:00:54.467241 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115268620}], length 0
17:00:54.467372 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115269966}], length 0
17:00:54.467496 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115271312}], length 0
17:00:54.467689 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115272658}], length 0
17:00:54.467812 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115274004}], length 0
17:00:54.468028 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115275350}], length 0
17:00:54.468190 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115276696}], length 0
17:00:54.468323 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393173 ecr 11940357,nop,nop,sack 1 {115239008:115278042}], length 0
17:00:54.468435 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115279388}], length 0
17:00:54.468609 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115280734}], length 0
17:00:54.468730 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115282080}], length 0
17:00:54.468857 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115283426}], length 0
17:00:54.468933 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115284772}], length 0
17:00:54.469084 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115286118}], length 0
17:00:54.469217 IP 10.8.0.2.bacula-sd > robotics.59654: Flags [.], ack 115199974, win 6928, options [nop,nop,TS val 2393174 ecr 11940357,nop,nop,sack 1 {115239008:115287464}], length 0
I tried to tune network stacks on both servers and to set Heartbeat Interval parameters into configs. But the problem still exists. Now I can not process any backup larger than pair hundreds of megabytes from the remote server.
Do anybody know the workaround for this issue?
