Bug#1009231: Write errors since upgrade to 9.6.7-4

[Klaus Ethgen]

Package: bacula-director
Version: 9.6.7-4
Severity: normal

Since upgrade from 9.6.7-3 to 9.6.7-4 I get many of the following errors
in the log. However, the backup seems to work.

JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57050: ERR=Broken pipe
JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57074: ERR=Broken pipe
...
JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57134: ERR=Connection reset by peer
JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57126: ERR=Connection reset by peer
...

Sometimes it is 4 bytes, sometimes 40 bytes. Sometimes Broken pipe,
sometimes Connection reset by peer. Sometimes only few, sometimes many.
I found no rule or source for the errors but they comes with every
backup.

-- System Information:
Debian Release: bookworm/sid
APT prefers experimental
APT policy: (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 5.16.17 (SMP w/8 CPU threads)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_FIRMWARE_WORKAROUND, TAINT_OOT_MODULE
Locale: LANG=C, LC_CTYPE=C.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /bin/dash
Init: sysvinit (via /sbin/init)

Versions of packages bacula-director depends on:
ii bacula-common 9.6.7-4
ii bacula-director-sqlite3 9.6.7-4
ii bsd-mailx [mailx] 8.1.2-0.20180807cvs-2
ii init-system-helpers 1.62devuan1
ii libc6 2.33-7
ii libstdc++6 12-20220319-1
ii lsb-base 11.1.0
ii ucf 3.0043

bacula-director recommends no packages.

Versions of packages bacula-director suggests:
ii bacula-doc 9.6.7-1

-- Configuration Files:
/etc/bacula/scripts/baculabackupreport changed [not included]
/etc/bacula/scripts/query.sql changed [not included]

-- no debconf information

--
Klaus Ethgen http://www.ethgen.ch/
pub 4096R/4E20AF1C 2011-05-16 Klaus Ethgen <Kl...@Ethgen.ch>
Fingerprint: 85D4 CA42 952C 949B 1753 62B3 79D0 B06F 4E20 AF1C

[Sven Hartge]

On 09.04.22 12:12, Klaus Ethgen wrote:

> Since upgrade from 9.6.7-3 to 9.6.7-4 I get many of the following errors
> in the log. However, the backup seems to work.
>
> JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57050: ERR=Broken pipe
> JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57074: ERR=Broken pipe
> ...
> JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57134: ERR=Connection reset by peer
> JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57126: ERR=Connection reset by peer
> ...

Hello Klaus,

I have not been able to reproduce this nor am I seeing this on any of my
systems.

Please check that the version of bacula-sd matches the one from
bacula-director and that bacula-fd is of no higher version than the
Director and the SD.

Also seeing "Connection reset by peer" while connecting via localhost is
very suspicious, IMHO. Is the FD dying during the backup?

What do you system logs and dmesg show during the exact time this happens?

> ii init-system-helpers 1.62devuan1

This looks like a mixed Debian/Devuan system. Can you make sure to
reproduce the bug in a clean Debian system, to rule out anything being
affected by changes made for Devuan.

Grüße,
Sven.

[Klaus Ethgen]

Hi Sven,

Am Fr den 15. Apr 2022 um 10:52 schrieb Sven Hartge:
> > Since upgrade from 9.6.7-3 to 9.6.7-4 I get many of the following errors
> > in the log. However, the backup seems to work.
> >
> > JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57050: ERR=Broken pipe
> > JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57074: ERR=Broken pipe
> > ...
> > JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57134: ERR=Connection reset by peer
> > JobId 0: Security Alert: bsock.c:380 Write error sending 4 bytes to client:127.0.0.1:57126: ERR=Connection reset by peer
> > ...
>
> Hello Klaus,
>
> I have not been able to reproduce this nor am I seeing this on any of my
> systems.
>
> Please check that the version of bacula-sd matches the one from
> bacula-director and that bacula-fd is of no higher version than the Director
> and the SD.

That is the case:
~> dpkg -l bacula\*
Gewünscht=Unbekannt/Installieren/R=Entfernen/P=Vollständig Löschen/Halten
| Status=Nicht/Installiert/Config/U=Entpackt/halb konFiguriert/
Halb installiert/Trigger erWartet/Trigger anhängig
|/ Fehler?=(kein)/R=Neuinstallation notwendig (Status, Fehler: GROSS=schlecht)
||/ Name Version Architektur Beschreibung
+++-========================-============-============-======================================================
ii bacula-bscan 9.6.7-4 amd64 network backup service - bscan tool
ii bacula-common 9.6.7-4 amd64 network backup service - common support files
ii bacula-common-sqlite3 9.6.7-4 amd64 network backup service - SQLite v3 common files
ii bacula-console 9.6.7-4 amd64 network backup service - text console
ii bacula-console-qt 9.6.7-4 amd64 network backup service - Bacula Administration Tool
ii bacula-director 9.6.7-4 amd64 network backup service - Director daemon
ii bacula-director-sqlite3 9.6.7-4 all network backup service - SQLite 3 storage for Director
ii bacula-doc 9.6.7-1 all Documentation for Bacula
ii bacula-fd 9.6.7-4 amd64 network backup service - file daemon
ii bacula-sd 9.6.7-4 amd64 network backup service - storage daemon

Funny fact: I also have systems with version 9.4.2 FD doing the backup
to this system and they do not trigger my problem over the network. Only
the localhost connections from the very same system does.

> Also seeing "Connection reset by peer" while connecting via localhost is
> very suspicious, IMHO. Is the FD dying during the backup?

I thought the same.

And no, the fd is not dying and the backup is completed without other
troubles.

But maybe I have some hints. About a half a year ago I added a host
living in untrusted network, so I changed the configuration to be mixed
clear communication over trusted network and encrypted for the rest.
Therefor, I have the following in director config:

Client xxx
{
...
TLS Enable = yes
TLS Require = yes
TLS CA Certificate File = /etc/ssl/private/bacula-ca.pem
TLS Certificate = /etc/ssl/private/bacula-dir.cert
TLS Key = /etc/ssl/private/bacula-dir.key
}

All other TLS settings are off.

I also have a nagios bacula monitor running every 5 minutes.
(/usr/lib/nagios/plugins/check_bacula) But this seems to stay green all
the time.

> What do you system logs and dmesg show during the exact time this happens?
>
> > ii init-system-helpers 1.62devuan1
>
> This looks like a mixed Debian/Devuan system. Can you make sure to reproduce
> the bug in a clean Debian system, to rule out anything being affected by
> changes made for Devuan.

No, I completely migrated to devuan some years ago due to the
systemd-debakel. I do not have any debian system left.

Gruß
Klaus

[Sven Hartge]

On 15.04.22 13:29, Klaus Ethgen wrote:

> I also have a nagios bacula monitor running every 5 minutes.
> (/usr/lib/nagios/plugins/check_bacula) But this seems to stay green all
> the time.

The log entries you see might be just from that check and not from the
running backup, just intermingled within the logs.

The "JobId: 0" makes me think this is the case.

Can you disable the Nagios check to see if this changes anything?

Grüße,
Sven.