Copying jobs from disk to tape fails with "Copying Error"

[jens.gr...@gmail.com]

Hi guys,

a week ago I realized that my backups to tape didn't work anymore. The setup is like

• backup clients to a diskpool on my bareos server (runs director and storage daemon)
• in the evening copy all the jobs to tape

I'm using version 23.0.3~pre47.36e516c0b-72 for all bareos packages.

To reproduce and force the error I setup a "OnetimeDisk2Tape"-job that selects just one job to be copied. When I manually run the job in the bconsole I get this output:

*setdebug level=150 trace=1 timestamp=1 storage=Tape
Connecting to Storage daemon Tape at g10-YYY.lan.XXX.AA:9103
3000 OK setdebug=150 trace=1 timestamp=1 tracefile=/var/lib/bareos/bareos-sd.trace
*setdebug level=150 trace=1 timestamp=1 dir
level=150 trace=1 hangup=0 timestamp=1 tracefilename=/var/lib/bareos/bareos-dir.trace
*run

<snip>

manual job configuration

</snip>

OK to run? (yes/mod/no): yes
Job queued. JobId=40600
*m
28-Mär 08:56 bareos-dir JobId 40600: The following 1 JobId was chosen to be copied: 40560
28-Mär 08:56 bareos-dir JobId 40600: Automatically selected Catalog: MyCatalog
28-Mär 08:56 bareos-dir JobId 40600: Using Catalog "MyCatalog"
28-Mär 08:56 bareos-dir JobId 40601: Copying using JobId=40560 Job=g-XXX-full.2024-03-27_13.05.00_30
28-Mär 08:56 bareos-dir JobId 40601: Bootstrap records written to /var/lib/bareos/bareos-dir.restore.24.bsr
28-Mär 08:56 bareos-dir JobId 40600: Job queued. JobId=40601
28-Mär 08:56 bareos-dir JobId 40600: Copying JobId 40601 started.
28-Mär 08:56 bareos-dir JobId 40600: Bareos bareos-dir 23.0.3~pre47.36e516c0b (19Mar24):
  Build OS:               Debian GNU/Linux 12 (bookworm)
  Current JobId:          40600
  Current Job:            OnetimeDisk2Tape.2024-03-28_08.56.00_18
  Catalog:                "MyCatalog" (From Default catalog)
  Start time:             28-Mär-2024 08:56:02
  End time:               28-Mär-2024 08:56:02
  Elapsed time:           0 secs
  Priority:               10
  Bareos binary info:     Bareos community build (UNSUPPORTED): Get professional support from https://www.bareos.com
  Job triggered by:       User
  Termination:            Copying OK

28-Mär 08:56 bareos-dir JobId 40601: Start Copying JobId 40601, Job=OnetimeDisk2Tape.2024-03-28_08.56.02_19
28-Mär 08:56 bareos-dir JobId 40601: Connected Storage daemon at g10-YYY.lan.XXX.AA:9103, encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
28-Mär 08:56 bareos-dir JobId 40601:  Encryption: TLS_CHACHA20_POLY1305_SHA256 TLSv1.3
28-Mär 08:56 bareos-dir JobId 40601: Using Device "FileStorage1" to read.
28-Mär 08:56 bareos-dir JobId 40601: Using Device "IBM-Drive-0" to write.
28-Mär 08:56 bareos-sd JobId 40601: Ready to read from volume "diskpool-0450" on device "FileStorage1" (/bareos/diskpool).
28-Mär 08:56 bareos-sd JobId 40601: Forward spacing Volume "diskpool-0450" to file:block 13:1846908481.
*setdebug level=0 trace=0 timestamp=1 dir
level=0 trace=0 hangup=0 timestamp=1 tracefilename=/var/lib/bareos/bareos-dir.trace
You have messages.
*setdebug level=0 trace=0 timestamp=1 storage=Tape
Connecting to Storage daemon Tape at g10-YYY.lan.XXX.AA:9103
3000 OK setdebug=0 trace=0 timestamp=1 tracefile=/var/lib/bareos/bareos-sd.trace
*m

28-Mär 08:56 bareos-dir JobId 40601: Insert of attributes batch table with 1400 entries start
28-Mär 08:56 bareos-dir JobId 40601: Insert of attributes batch table done
28-Mär 08:56 bareos-dir JobId 40601: Error: Bareos bareos-dir 23.0.3~pre47.36e516c0b (19Mar24):
  Build OS:               Debian GNU/Linux 12 (bookworm)
  Prev Backup JobId:      40560
  Prev Backup Job:        g-XXX-full.2024-03-27_13.05.00_30
  New Backup JobId:       40602
  Current JobId:          40601
  Current Job:            OnetimeDisk2Tape.2024-03-28_08.56.02_19
  Backup Level:           Incremental
  Client:                 XXX-fd
  FileSet:                "LinuxXXX"
  Read Pool:              "diskpool" (From Job resource)
  Read Storage:           "File-g10" (From previous Job)
  Write Pool:             "Week4" (From Run NextPool override)
  Write Storage:          "Tape" (From Storage from Run NextPool override)
  Next Pool:              "Week4" (From Run NextPool override)
  Catalog:                "MyCatalog" (From Default catalog)
  Start time:             28-Mär-2024 08:56:04
  End time:               28-Mär-2024 08:56:34
  Elapsed time:           30 secs
  Priority:               10
  SD Files Written:       0
  SD Bytes Written:       265,505 (265.5 KB)
  Rate:                   8.9 KB/s
  Volume name(s):         WOC2-4L79
  Volume Session Id:      70
  Volume Session Time:    1711461892
  Last Volume Bytes:      55,466,384,384 (55.46 GB)
  SD Errors:              0
  SD termination status:  Running
  Bareos binary info:     Bareos community build (UNSUPPORTED): Get professional support from https://www.bareos.com
  Job triggered by:       User
  Termination:            *** Copying Error ***

This is also the info in /var/log/bareos/bareos.log.

I've tried to cut the tracing-output to only contain the lines concerning this job. I've obfuscated the host names and removed the list of files to be inserted into the database. These two files are attached. Unfortunately I have no idea where to look exactly. For me there is no obvious error message or some information that points me in a certain direction.

This ist what I've tried so far:

• running different copy jobs. Result: only jobs with very few files are copied, bigger jobs always fail
• cleaning the drive (although not needed according to the drive): no difference
• using different tapes: no matter which tape I try, the copy jobs fail
• running a job directly to tape: job runs without problems

Can anyone help me out?

Greetings, Jens