Diese Website existiert nur weil wir Werbung mit AdSense ausliefern.
Bitte den AdBlocker daher auf dieser Website ausschalten! Danke.

bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Alles rund um die Server (Web-, Mail-, Datenbank-, Datenaustausch-, etc.) die man unter Linux betreiben kann

Moderator: Moderatoren

Antworten
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

Moin *

Mehrere Clients auf Basis von Fedora werden plötzlich nicht mehr durch Bacula gesichert.

Serverseitiges Log:

Code: Alles auswählen

25-Apr 09:45 bacula-dir JobId 3773: Created new Volume="inc-j10-2.2021-04-25_09.45.05_16-3773-108", Pool="j10-2-inc", MediaType="File2" in catalog.
25-Apr 09:45 bacula-dir JobId 3773: Using Device "disk2-j10" to write.
25-Apr 09:45 bacula-dir JobId 3773: Error: getmsg.c:209 Malformed message: Events: code=FC0002 daemon=j10-fd ref=0x7f086400b328 type=connection source=bacula-dir text=Director connection

25-Apr 09:45 j10-fd JobId 3773: Fatal error: hello.c:191 Bad caps from SD: auth cram-md5 <1220413786.1619336706@bacula-sd> ssl=0
.
25-Apr 09:45 bacula-dir JobId 3773: Fatal error: Bad response to Storage command: wanted 2000 OK storage
, got 2800 End Job TermCode=102 JobFiles=0 ReadBytes=0 JobBytes=0 Errors=1 VSS=0 Encrypt=0 CommBytes=64 CompressCommBytes=64

25-Apr 09:45 bacula-dir JobId 3773: Fatal error: No Job status returned from FD.
25-Apr 09:45 bacula-dir JobId 3773: Error: Bacula bacula-dir 9.0.6 (20Nov17):
  Build OS:               x86_64-redhat-linux-gnu redhat (Core)
  JobId:                  3773
  Job:                    j10-2.2021-04-25_09.45.05_16
  Backup Level:           Incremental, since=2021-04-24 09:42:07
  Client:                 "j10-fd" 11.0.2 (26Mar21) x86_64-redhat-linux-gnu,redhat,Three)
  FileSet:                "full linux client - by FS-Type" 2020-08-10 09:37:53
  Pool:                   "j10-2-inc" (From Job IncPool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "File2-j10" (From Pool resource)
  Scheduled time:         25-Apr-2021 09:45:05
  Start time:             25-Apr-2021 09:45:05
  End time:               25-Apr-2021 09:45:06
  Elapsed time:           1 sec
  Priority:               10
  FD Files Written:       0
  SD Files Written:       0
  FD Bytes Written:       0 (0 B)
  SD Bytes Written:       0 (0 B)
  Rate:                   0.0 KB/s
  Software Compression:   None
  Comm Line Compression:  None
  Snapshot/VSS:           no
  Encryption:             no
  Accurate:               no
  Volume name(s):         
  Volume Session Id:      3928
  Volume Session Time:    1617295640
  Last Volume Bytes:      0 (0 B)
  Non-fatal FD errors:    1
  SD Errors:              0
  FD termination status:  Error
  SD termination status:  Waiting on FD
  Termination:            *** Backup Error ***

25-Apr 09:45 bacula-dir JobId 3773: Rescheduled Job j10-2.2021-04-25_09.45.05_16 at 25-Apr-2021 09:45 to re-run in 3600 seconds (25-Apr-2021 10:45).
25-Apr 09:45 bacula-dir JobId 3773: Job j10-2.2021-04-25_09.45.05_16 waiting 3600 seconds for scheduled start time.
25-Apr 10:45 bacula-dir JobId 3773: Start Backup JobId 3773, Job=j10-2.2021-04-25_09.45.05_16
25-Apr 10:45 bacula-dir JobId 3773: Using Device "disk2-j10" to write.
25-Apr 10:45 bacula-dir JobId 3773: Warning: bsock.c:141 Could not connect to Client: j10-fd on j10-wlan:9102. ERR=Keine Route zum Zielrechner

Status des Clients:

Code: Alles auswählen

● bacula-fd.service - Bacula File Daemon
     Loaded: loaded (/usr/lib/systemd/system/bacula-fd.service; enabled; vendor preset: disabled)
     Active: active (running) since Mon 2021-04-26 11:56:11 CEST; 1 weeks 3 days ago
       Docs: man:bacula-fd(8)
   Main PID: 117188 (bacula-fd)
      Tasks: 3 (limit: 9380)
     Memory: 1.7M
        CPU: 359ms
     CGroup: /system.slice/bacula-fd.service
             └─117188 /usr/sbin/bacula-fd -f -c /etc/bacula/bacula-fd.conf -u root -g root

Mai 04 06:37:08 j10.gehrke.local bacula-fd[117188]: j10-fd: hello.c:191-3889 Bad caps from SD: auth cram-md5 <1847218702.1620103029@bacula-sd> ssl=0
Mai 04 06:37:08 j10.gehrke.local bacula-fd[117188]: .
Mai 05 21:19:16 j10.gehrke.local bacula-fd[117188]: j10-fd: hello.c:191-3921 Bad caps from SD: auth cram-md5 <248210867.1620242356@bacula-sd> ssl=0
Mai 05 21:19:16 j10.gehrke.local bacula-fd[117188]: .
Mai 06 07:47:26 j10.gehrke.local bacula-fd[117188]: j10-fd: hello.c:191-3921 Bad caps from SD: auth cram-md5 <850501153.1620280046@bacula-sd> ssl=0
Mai 06 07:47:26 j10.gehrke.local bacula-fd[117188]: .
Mai 06 16:03:49 j10.gehrke.local bacula-fd[117188]: j10-fd: hello.c:191-3937 Bad caps from SD: auth cram-md5 <530996766.1620309829@bacula-sd> ssl=0
Mai 06 16:03:49 j10.gehrke.local bacula-fd[117188]: .
Mai 06 19:10:10 j10.gehrke.local bacula-fd[117188]: j10-fd: hello.c:191-3937 Bad caps from SD: auth cram-md5 <471440642.1620321010@bacula-sd> ssl=0
Mai 06 19:10:10 j10.gehrke.local bacula-fd[117188]: .
Zuvor lief das jahrelang problemlos und Konfigurationsänderungen sind mir nicht bekannt.

Das fällt zeitlich frapierend zusammen mit einem Systemupgrade:

Code: Alles auswählen

# dnf history info 620
Transaktions-ID : 620
Anfangszeit : So 25 Apr 2021 09:44:50 CEST
Anfang rpmdb    : 2935:8062501e559f7fa62f245cd2dfae0729d916d470
Endzeit : So 25 Apr 2021 09:45:04 CEST (14 Sekunden)
Ende rpmdb      : 2935:3069174b9216528fe2a02a6eaef4dc04cf014ee5
Benutzer : System <nicht gesetzt>
Rückgabe-Code    : Erfolg
Releasever: 33
Befehlszeile   : 
Kommentar        : 
Veränderte Pakete:
    Upgrade  bacula-client-11.0.2-3.fc33.x86_64                   @updates
    Upgraded bacula-client-9.6.7-1.fc33.x86_64                    @@System
    Upgrade  bacula-common-11.0.2-3.fc33.x86_64                   @updates
    Upgraded bacula-common-9.6.7-1.fc33.x86_64                    @@System
    Upgrade  bacula-libs-11.0.2-3.fc33.x86_64                     @updates
    Upgraded bacula-libs-9.6.7-1.fc33.x86_64                      @@System
Eine Recherche zeigt lediglich wenig hilfreiche Einträge von vor 2016. Scheint etwas neues zu sein.

Glückauf, gehrke
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

Ich versuche es mal mit einer älteren clientseitigen Version:

Code: Alles auswählen

# dnf downgrade bacula-client
Letzte Prüfung auf abgelaufene Metadaten: vor 3:18:37 am Do 06 Mai 2021 18:52:41 CEST.
Abhängigkeiten sind aufgelöst.
========================================================================================================================================================
 Package                                 Architecture                     Version                                Repository                        Size
========================================================================================================================================================
Herunterstufen:
 bacula-client                           x86_64                           9.6.5-2.fc33                           fedora                           144 k
 bacula-common                           x86_64                           9.6.5-2.fc33                           fedora                            18 k
 bacula-libs                             x86_64                           9.6.5-2.fc33                           fedora                           543 k

Transaktionsübersicht
========================================================================================================================================================
Zurücksetzen  3 Pakete

Gesamte Downloadgröße: 705 k
Ist dies in Ordnung? [j/N]: j
Pakete werden heruntergeladen:
(1/3): bacula-common-9.6.5-2.fc33.x86_64.rpm                                                                            154 kB/s |  18 kB     00:00    
(2/3): bacula-client-9.6.5-2.fc33.x86_64.rpm                                                                            507 kB/s | 144 kB     00:00    
(3/3): bacula-libs-9.6.5-2.fc33.x86_64.rpm                                                                              1.2 MB/s | 543 kB     00:00    
--------------------------------------------------------------------------------------------------------------------------------------------------------
Gesamt                                                                                                                  826 kB/s | 705 kB     00:00     
Transaktionsüberprüfung wird ausgeführt
Transaktionsprüfung war erfolgreich.
Transaktion wird getestet
Transaktionstest war erfolgreich.
Transaktion wird ausgeführt
  Vorbereitung läuft    :                                                                                                                           1/1 
  Ausgeführtes Scriptlet: bacula-libs-9.6.5-2.fc33.x86_64                                                                                           1/1 
  Downgrading           : bacula-libs-9.6.5-2.fc33.x86_64                                                                                           1/6 
  Ausgeführtes Scriptlet: bacula-common-9.6.5-2.fc33.x86_64                                                                                         2/6 
  Downgrading           : bacula-common-9.6.5-2.fc33.x86_64                                                                                         2/6 
  Downgrading           : bacula-client-9.6.5-2.fc33.x86_64                                                                                         3/6 
Warnung: /etc/bacula/bacula-fd.conf erstellt als /etc/bacula/bacula-fd.conf.rpmnew

  Ausgeführtes Scriptlet: bacula-client-9.6.5-2.fc33.x86_64                                                                                         3/6 
  Ausgeführtes Scriptlet: bacula-client-11.0.2-3.fc33.x86_64                                                                                        4/6 
  Aufräumen             : bacula-client-11.0.2-3.fc33.x86_64                                                                                        4/6 
  Ausgeführtes Scriptlet: bacula-client-11.0.2-3.fc33.x86_64                                                                                        4/6 
  Aufräumen             : bacula-common-11.0.2-3.fc33.x86_64                                                                                        5/6 
  Aufräumen             : bacula-libs-11.0.2-3.fc33.x86_64                                                                                          6/6 
  Ausgeführtes Scriptlet: bacula-libs-11.0.2-3.fc33.x86_64                                                                                          6/6 
  Überprüfung läuft     : bacula-client-9.6.5-2.fc33.x86_64                                                                                         1/6 
  Überprüfung läuft     : bacula-client-11.0.2-3.fc33.x86_64                                                                                        2/6 
  Überprüfung läuft     : bacula-common-9.6.5-2.fc33.x86_64                                                                                         3/6 
  Überprüfung läuft     : bacula-common-11.0.2-3.fc33.x86_64                                                                                        4/6 
  Überprüfung läuft     : bacula-libs-9.6.5-2.fc33.x86_64                                                                                           5/6 
  Überprüfung läuft     : bacula-libs-11.0.2-3.fc33.x86_64                                                                                          6/6 

Zurückgesetzt:
  bacula-client-9.6.5-2.fc33.x86_64                  bacula-common-9.6.5-2.fc33.x86_64                  bacula-libs-9.6.5-2.fc33.x86_64                 

Fertig.
Und ja, sieht gut aus. Die ersten 223 MB werden soeben gesichert. Ich gehe davon aus, dass das erfolgreich durchläuft.

Aber das ist natürlich nur ein erstes Indiz, dass die neue Version buggy ist oder mit der serverseitigen Version nicht kompatibel ist.
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

Ach so, wenn schon Workaround, dann wenigstens fix:

Code: Alles auswählen

# dnf versionlock add bacula-client-9.6.5-2.fc33.x86_64 bacula-common-9.6.5-2.fc33.x86_64 bacula-libs-9.6.5-2.fc33.x86_64
Letzte Prüfung auf abgelaufene Metadaten: vor 3:38:03 am Do 06 Mai 2021 18:52:41 CEST.
Versionssperre wird hinzugefügt zu: bacula-libs-0:9.6.5-2.fc33.*
Versionssperre wird hinzugefügt zu: bacula-client-0:9.6.5-2.fc33.*
Versionssperre wird hinzugefügt zu: bacula-common-0:9.6.5-2.fc33.*
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

Der obige Workaround funktioniert hässlich, aber stabil für die Clients mit Fedora 33.

Einer meiner Clients ist aber schon frisch auf Fedora 34. Auch dort scheitert das Backup:

Code: Alles auswählen

08-Mai 13:27 j12-fd JobId 3983: Fatal error: hello.c:191 Bad caps from SD: auth cram-md5 <1882231691.1620473249@bacula-sd> ssl=0
.
08-Mai 13:27 bacula-dir JobId 3983: Fatal error: Bad response to Storage command: wanted 2000 OK storage
, got 2800 End Job TermCode=102 JobFiles=0 ReadBytes=0 JobBytes=0 Errors=1 VSS=0 Encrypt=0 CommBytes=64 CompressCommBytes=64

08-Mai 13:27 bacula-dir JobId 3983: Fatal error: No Job status returned from FD.

08-Mai 13:28 bacula-dir JobId 0: Error: getmsg.c:209 Malformed message: Events: code=FC0002 daemon=j12-fd ref=0x7f8b2400b098 type=connection source=bacula-dir text=Director connection

Code: Alles auswählen

[root@j12 ~]# systemctl status bacula-fd.service 
● bacula-fd.service - Bacula File Daemon
     Loaded: loaded (/usr/lib/systemd/system/bacula-fd.service; enabled; vendor preset: disabled)
     Active: active (running) since Sat 2021-05-08 12:01:43 CEST; 1h 19min ago
       Docs: man:bacula-fd(8)
   Main PID: 1420 (bacula-fd)
      Tasks: 3 (limit: 9111)
     Memory: 3.0M
        CPU: 36ms
     CGroup: /system.slice/bacula-fd.service
             └─1420 /usr/sbin/bacula-fd -f -c /etc/bacula/bacula-fd.conf -u root -g root

Mai 08 12:01:43 j12 systemd[1]: Started Bacula File Daemon.
Mai 08 13:13:30 j12 bacula-fd[1420]: job.c:548 FD expecting Hello got bad command from 172.16.21.11. Len=-4.
Mai 08 13:14:03 j12 bacula-fd[1420]: j12-fd: hello.c:191-3982 Bad caps from SD: auth cram-md5 <1823788466.1620472443@bacula-sd> ssl=0
Mai 08 13:14:03 j12 bacula-fd[1420]: .
Mai 08 13:18:38 j12 bacula-fd[1420]: job.c:548 FD expecting Hello got bad command from 172.16.21.11. Len=-720899.

Code: Alles auswählen

[root@j12 ~]# dnf info bacula-client
Installierte Pakete
Name         : bacula-client
Version      : 11.0.2
Release      : 3.fc34
Architecture : x86_64
Size         : 591 k
Quelle       : bacula-11.0.2-3.fc34.src.rpm
Repository   : @System
Aus Paketque : updates
Summary      : Bacula backup client
URL          : http://www.bacula.org
Lizenz       : AGPLv3 with exceptions
Description  : Bacula is a set of programs that allow you to manage the backup, recovery, and
             : verification of computer data across a network of different computers. It is
             : based on a client/server architecture.
             : 
             : This package contains the bacula client, the daemon running on the system to be
             : backed up.
Ein Downgrade führt hier zu einer nur marginal veränderten Version, die das selbe Verhalten zeigt:

Code: Alles auswählen

(1/3): bacula-common-11.0.1-1.fc34.x86_64.rpm                                                            260 kB/s |  18 kB     00:00    
(2/3): bacula-client-11.0.1-1.fc34.x86_64.rpm                                                            1.5 MB/s | 227 kB     00:00    
(3/3): bacula-libs-11.0.1-1.fc34.x86_64.rpm                                                              2.5 MB/s | 593 kB     00:00    
-----------------------------------------------------------------------------------------------------------------------------------------
Gesamt                                                                                                   2.3 MB/s | 838 kB     00:00     
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
spoensche
Moderator
Moderator
Beiträge: 7587
Registriert: 30. Okt 2004, 23:53
Wohnort: Siegen

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von spoensche »

Neue Client Version, alte Fd Version bzw. alte Director Version, richtig?

Zwischen Version 9 und 11 ist der Unterschied nicht gerade gering. Unterschiedliche Protokollversionen können z.B. zu diesem Problem führen.
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

Ja, es ist der Spagat der Versionen. Aber damit muss Bacula klarkommen, so war es immer schon und so ist es auch dokumentiert. Denn sonst gibt es in so heterogenen Umgebungen wie meiner sehr schnell Probleme. Da gibt es hochaktuelle Clients mit Fedora 34 neben Debian 9 und CentOS 7.
Bislang war das kein Problem.
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
marce
Advanced Hacker
Advanced Hacker
Beiträge: 1383
Registriert: 19. Jun 2008, 13:16
Wohnort: Dettenhausen
Kontaktdaten:

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von marce »

Ggf. bei Bacula ein Bugticket aufmachen...
Benutzeravatar
gehrke
Moderator
Moderator
Beiträge: 2423
Registriert: 10. Nov 2012, 11:00

Re: bacula: Fatal error: Bad response to Storage command: wanted 2000 OK storage , got 2800 End Job TermCode=102

Beitrag von gehrke »

marce hat geschrieben: 11. Mai 2021, 06:33 Ggf. bei Bacula ein Bugticket aufmachen...
Ja, darauf wird es hinauslaufen.
Keinen Bock mehr auf zentralisierte soziale Netzwerke von US-Konzernen?
https://www.kuketz-blog.de/das-fedivers ... nteressen/ (Join the fediverse: Friendica, Mastodon, Diaspora und vieles mehr)
Antworten