View Issue Details

IDProjectCategoryView StatusLast Update
0001103bareos-core[All Projects] storage daemonpublic2019-07-31 15:53
ReporterSchroeffuAssigned To 
PrioritylowSeveritytextReproducibilityN/A
Status feedbackResolutionopen 
PlatformLinuxOSUbuntuOS Version18.04
Product Version18.2.5 
Target VersionFixed in Version 
Summary0001103: Bareos with warnings of bareos-fd Incremental
DescriptionSince Upgrade Bareos 17 to 18.2.5 on Ubuntu 18.04 , i get every daily backup two notifications:

1. 26-Jun 21:00 bareos-sd JobId 3786: Error: Bareos cannot write on disk Volume "Incremental-0017" because: The sizes do not match! Volume=641 Catalog=625999556

2. 27-Jun 00:20 bareos-sd JobId 3788: Warning: For Volume "Incremental-0103":
The sizes do not match! Volume=1073696951 Catalog=18148 Correcting Catalog 27-Jun 00:20 bareos-sd JobId 3788: Job vmlxgitlab01bs-Default.2019-06-27_00.20.00_05 is waiting. Cannot find any appendable volumes.
Please use the "label" command to create a new Volume for:
    Storage: "FileStorage-vmbaksrv01bs" (/bareos-backup-dir)
    Pool: Incremental
    Media type: File

Looks like only a warning, because it is "Correcting Catalog" as I see in the messages. And a test done to recovery something on the host ist also ok.

I can't stop these messages, so how can I make this correct for the future to not get this messages anymore?
Steps To Reproducenot sure. i just upgraded to the latest bareos version available for Ubuntu 18.04, since then the issue exists.
TagsNo tags attached.
bareos-master: impact
bareos-master: action
bareos-18.2: impact
bareos-18.2: action
bareos-17.2: impact
bareos-17.2: action
bareos-16.2: impact
bareos-16.2: action
bareos-15.2: impact
bareos-15.2: action
bareos-14.2: impact
bareos-14.2: action
bareos-13.2: impact
bareos-13.2: action
bareos-12.4: impact
bareos-12.4: action

Activities

Schroeffu

Schroeffu

2019-07-22 11:29

reporter   ~0003516

Ignore the extended error message of 2., i copied wrong one (there was really the appenable volumes full)
the right daily warning i want to resolve is:

20-Jul 00:20 bareos-sd JobId 4077: Warning: For Volume "Incremental-0091":
The sizes do not match! Volume=1073702232 Catalog=641 Correcting Catalog
arogge

arogge

2019-07-22 13:02

developer   ~0003518

If you get "The sizes do not match!" this means the volume information in the catalog has not been updated.
This can happen when a previous job has failed miserably.
Does it happen with different volumes or just with Incremental-0017?
Can you provide the joblogs for tje job that wrote to the same volume before (list joblog)?
Schroeffu

Schroeffu

2019-07-30 09:59

reporter   ~0003533

Got what you mean, it seems to be the Fileset SelfTest backup-bareos-fd which runs 21:00 before:

*list joblog jobid=4185
 2019-07-29 21:00:02 bareos-dir JobId 4185: Start Backup JobId 4185, Job=backup-bareos-fd.2019-07-29_21.00.00_45
 2019-07-29 21:00:02 bareos-dir JobId 4185: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:00:03 bareos-dir JobId 4185: Using Device "FileStorage" to write.
 2019-07-29 21:00:03 bareos-dir JobId 4185: Connected Client: bareos-fd at localhost:9102, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:00:03 bareos-dir JobId 4185: Handshake: Immediate TLS 2019-07-29 21:00:03 bareos-dir JobId 4185: Encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:00:03 vmlxbareos01bs-fd JobId 4185: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:00:03 bareos-sd JobId 4185: Warning: Volume "Incremental-0163" not on device "FileStorage" (/var/lib/bareos/storage).
 2019-07-29 21:00:03 vmlxbareos01bs-fd JobId 4185: Extended attribute support is enabled
 2019-07-29 21:00:03 vmlxbareos01bs-fd JobId 4185: ACL support is enabled
 2019-07-29 21:00:03 bareos-sd JobId 4185: Marking Volume "Incremental-0163" in Error in Catalog.
 2019-07-29 21:00:03 bareos-sd JobId 4185: Warning: Volume "Incremental-0163" not on device "FileStorage" (/var/lib/bareos/storage).
 2019-07-29 21:00:03 bareos-sd JobId 4185: Marking Volume "Incremental-0163" in Error in Catalog.
 2019-07-29 21:00:03 bareos-sd JobId 4185: Warning: stored/mount.cc:270 Open device "FileStorage" (/var/lib/bareos/storage) Volume "Incremental-0163" failed: ERR=stored/dev.cc:731 Could not open: /var/lib/bareos/storage/Incremental-0163, ERR=No such file or directory

 2019-07-29 21:00:03 bareos-dir JobId 4185: There are no more Jobs associated with Volume "Incremental-0020". Marking it purged.
 2019-07-29 21:00:03 bareos-dir JobId 4185: All records pruned from Volume "Incremental-0020"; marking it "Purged"
 2019-07-29 21:00:03 bareos-dir JobId 4185: Recycled volume "Incremental-0020"
 2019-07-29 21:00:03 bareos-sd JobId 4185: Recycled volume "Incremental-0020" on device "FileStorage" (/var/lib/bareos/storage), all previous data lost.
 2019-07-29 21:00:03 bareos-sd JobId 4185: Releasing device "FileStorage" (/var/lib/bareos/storage).
 2019-07-29 21:00:03 bareos-sd JobId 4185: Elapsed time=00:00:01, Transfer rate=0 Bytes/second
 2019-07-29 21:00:03 bareos-dir JobId 4185: Bareos bareos-dir 18.2.5 (30Jan19):
  Build OS: Linux-4.4.92-6.18-default ubuntu Ubuntu 18.04 LTS
  JobId: 4185
  Job: backup-bareos-fd.2019-07-29_21.00.00_45
  Backup Level: Incremental, since=2019-07-27 21:00:02
  Client: "bareos-fd" 18.2.5 (30Jan19) Linux-4.4.92-6.18-default,ubuntu,Ubuntu 18.04 LTS,xUbuntu_18.04,x86_64
  FileSet: "SelfTest" 2018-05-04 16:53:55
  Pool: "Incremental" (From Job IncPool override)
  Catalog: "MyCatalog" (From Client resource)
  Storage: "File" (From Job resource)
  Scheduled time: 29-Jul-2019 21:00:00
  Start time: 29-Jul-2019 21:00:03
  End time: 29-Jul-2019 21:00:03
  Elapsed time: 0 secs
  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
  VSS: no
  Encryption: no
  Accurate: no
  Volume name(s): Incremental-0020
  Volume Session Id: 84
  Volume Session Time: 1563781778
  Last Volume Bytes: 641 (641 B)
  Non-fatal FD errors: 0
  SD Errors: 0
  FD termination status: OK
  SD termination status: OK
  Bareos binary info: bareos.org build: Get official binaries and vendor support on bareos.com
  Termination: Backup OK

*

But the place /var/lib/bareos/storage looks to me writeable, it has content from another backup job BackupCatalog Fileset Catalog:

ls -rtlha /var/lib/bareos/storage/
(...)
-rw-r----- 1 bareos bareos 641 Jul 16 21:00 Incremental-0213
-rw-r----- 1 bareos bareos 10G Jul 16 21:10 Full-0083
-rw-r----- 1 bareos bareos 641 Jul 17 21:00 Incremental-0137
-rw-r----- 1 bareos bareos 641 Jul 18 21:00 Incremental-0088
-rw-r----- 1 bareos bareos 641 Jul 19 21:00 Incremental-0091
-rw-r----- 1 bareos bareos 705K Jul 22 21:00 Incremental-0010
-rw-r----- 1 bareos bareos 641 Jul 23 21:00 Incremental-0264
-rw-r----- 1 bareos bareos 641 Jul 24 21:00 Incremental-0099
-rw-r----- 1 bareos bareos 641 Jul 25 21:00 Incremental-0156
drwxr-x--- 2 bareos bareos 4.0K Jul 26 21:00 .
-rw-r----- 1 bareos bareos 641 Jul 26 21:00 Incremental-0018
-rw-r----- 1 bareos bareos 836K Jul 27 21:00 Differential-0164
-rw-r----- 1 bareos bareos 641 Jul 29 21:00 Incremental-0020
-rw-r----- 1 bareos bareos 7.8G Jul 29 21:10 Full-0084

Log of this job:

*list joblog jobid=4186
Automatically selected Catalog: MyCatalog
Using Catalog "MyCatalog"
 2019-07-29 21:10:02 bareos-dir JobId 4186: shell command: run BeforeJob "/usr/lib/bareos/scripts/make_catalog_backup.pl MyCatalog"
 2019-07-29 21:10:32 bareos-dir JobId 4186: Start Backup JobId 4186, Job=BackupCatalog.2019-07-29_21.10.00_46
 2019-07-29 21:10:32 bareos-dir JobId 4186: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:10:32 bareos-dir JobId 4186: Using Device "FileStorage" to write.
 2019-07-29 21:10:33 bareos-dir JobId 4186: Connected Client: bareos-fd at localhost:9102, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:10:33 bareos-dir JobId 4186: Handshake: Immediate TLS 2019-07-29 21:10:33 bareos-dir JobId 4186: Encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:10:33 vmlxbareos01bs-fd JobId 4186: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-29 21:10:33 vmlxbareos01bs-fd JobId 4186: Extended attribute support is enabled
 2019-07-29 21:10:33 vmlxbareos01bs-fd JobId 4186: ACL support is enabled
 2019-07-29 21:10:33 bareos-sd JobId 4186: Volume "Full-0084" previously written, moving to end of data.
 2019-07-29 21:10:33 bareos-sd JobId 4186: Ready to append to end of Volume "Full-0084" size=7481695337
 2019-07-29 21:10:49 bareos-sd JobId 4186: Releasing device "FileStorage" (/var/lib/bareos/storage).
 2019-07-29 21:10:49 bareos-sd JobId 4186: Elapsed time=00:00:16, Transfer rate=49.89 M Bytes/second
 2019-07-29 21:10:49 bareos-dir JobId 4186: Insert of attributes batch table with 81 entries start
 2019-07-29 21:10:49 bareos-dir JobId 4186: Insert of attributes batch table done
 2019-07-29 21:10:49 bareos-dir JobId 4186: Bareos bareos-dir 18.2.5 (30Jan19):
  Build OS: Linux-4.4.92-6.18-default ubuntu Ubuntu 18.04 LTS
  JobId: 4186
  Job: BackupCatalog.2019-07-29_21.10.00_46
  Backup Level: Full
  Client: "bareos-fd" 18.2.5 (30Jan19) Linux-4.4.92-6.18-default,ubuntu,Ubuntu 18.04 LTS,xUbuntu_18.04,x86_64
  FileSet: "Catalog" 2018-05-04 21:10:00
  Pool: "Full" (From Job FullPool override)
  Catalog: "MyCatalog" (From Client resource)
  Storage: "File" (From Job resource)
  Scheduled time: 29-Jul-2019 21:10:00
  Start time: 29-Jul-2019 21:10:33
  End time: 29-Jul-2019 21:10:49
  Elapsed time: 16 secs
  Priority: 11
  FD Files Written: 81
  SD Files Written: 81
  FD Bytes Written: 798,320,279 (798.3 MB)
  SD Bytes Written: 798,330,193 (798.3 MB)
  Rate: 49895.0 KB/s
  Software Compression: None
  VSS: no
  Encryption: no
  Accurate: no
  Volume name(s): Full-0084
  Volume Session Id: 85
  Volume Session Time: 1563781778
  Last Volume Bytes: 8,280,620,204 (8.280 GB)
  Non-fatal FD errors: 0
  SD Errors: 0
  FD termination status: OK
  SD termination status: OK
  Bareos binary info: bareos.org build: Get official binaries and vendor support on bareos.com
  Termination: Backup OK

 2019-07-29 21:10:49 bareos-dir JobId 4186: shell command: run AfterJob "/usr/lib/bareos/scripts/delete_catalog_backup"
You have messages.

And then the other warning job is next:


*list joblog jobid=4187 [6/1835]
 2019-07-30 00:20:01 bareos-dir JobId 4187: Start Backup JobId 4187, Job=vmlxgitlab01bs-Default.2019-07-30_00.20.00_47
 2019-07-30 00:20:01 bareos-dir JobId 4187: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-30 00:20:01 bareos-dir JobId 4187: Using Device "FileStorage-vmbaksrv01bs" to write.
 2019-07-30 00:20:01 bareos-dir JobId 4187: Connected Client: vmlxgitlab01bs-fd at gitlab.kuechenaktuell.de:9102, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-30 00:20:01 bareos-dir JobId 4187: Handshake: Immediate TLS 2019-07-30 00:20:01 bareos-dir JobId 4187: Encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-30 00:20:01 vmlxgitlab01bs-fd JobId 4187: Connected Storage daemon at bareos:9103, encryption: TLS_CHACHA20_POLY1305_SHA256
 2019-07-30 00:20:01 vmlxgitlab01bs-fd JobId 4187: Extended attribute support is enabled
 2019-07-30 00:20:01 vmlxgitlab01bs-fd JobId 4187: ACL support is enabled
 2019-07-30 00:20:01 bareos-sd JobId 4187: Volume "Incremental-0020" previously written, moving to end of data.
 2019-07-30 00:20:01 bareos-sd JobId 4187: Warning: For Volume "Incremental-0020":
The sizes do not match! Volume=1073737890 Catalog=641
Correcting Catalog
 2019-07-30 00:20:30 bareos-sd JobId 4187: User defined maximum volume capacity 1,073,741,824 exceeded on device "FileStorage-vmbaksrv01bs" (/bareos-backup-dir).
 2019-07-30 00:20:30 bareos-sd JobId 4187: End of medium on Volume "Incremental-0020" Bytes=1,073,737,890 Blocks=1 at 30-Jul-2019 00:20.
 2019-07-30 00:20:30 bareos-dir JobId 4187: There are no more Jobs associated with Volume "Incremental-0038". Marking it purged.
 2019-07-30 00:20:30 bareos-dir JobId 4187: All records pruned from Volume "Incremental-0038"; marking it "Purged"
 2019-07-30 00:20:30 bareos-dir JobId 4187: Recycled volume "Incremental-0038"
 2019-07-30 00:20:30 bareos-sd JobId 4187: Recycled volume "Incremental-0038" on device "FileStorage-vmbaksrv01bs" (/bareos-backup-dir), all previous data lost.
 2019-07-30 00:20:30 bareos-sd JobId 4187: New volume "Incremental-0038" mounted on device "FileStorage-vmbaksrv01bs" (/bareos-backup-dir) at 30-Jul-2019 00:20.
 2019-07-30 00:21:02 vmlxgitlab01bs-fd JobId 4187: /var/lib/lxcfs is a different filesystem. Will not descend from / into it.
 2019-07-30 00:21:18 vmlxgitlab01bs-fd JobId 4187: /boot/efi is a different filesystem. Will not descend from / into it.
 2019-07-30 00:21:20 bareos-sd JobId 4187: Releasing device "FileStorage-vmbaksrv01bs" (/bareos-backup-dir).
 2019-07-30 00:21:20 bareos-sd JobId 4187: Elapsed time=00:01:19, Transfer rate=3.982 M Bytes/second
 2019-07-30 00:21:20 bareos-dir JobId 4187: Insert of attributes batch table with 1702 entries start
 2019-07-30 00:21:20 bareos-dir JobId 4187: Insert of attributes batch table done
 2019-07-30 00:21:20 bareos-dir JobId 4187: Bareos bareos-dir 18.2.5 (30Jan19):
  Build OS: Linux-4.4.92-6.18-default ubuntu Ubuntu 18.04 LTS
  JobId: 4187
  Job: vmlxgitlab01bs-Default.2019-07-30_00.20.00_47
  Backup Level: Incremental, since=2019-07-29 00:20:00
  Client: "vmlxgitlab01bs-fd" 18.2.5 (30Jan19) Linux-4.4.92-6.18-default,ubuntu,Ubuntu 18.04 LTS,xUbuntu_18.04,x86_64
  FileSet: "LinuxDefault" 2018-11-28 00:20:00
  Pool: "Incremental" (From Job IncPool override)
  Catalog: "MyCatalog" (From Client resource)
  Storage: "File-vmbaksrv01bs" (From Job resource)
  Scheduled time: 30-Jul-2019 00:20:00
  Start time: 30-Jul-2019 00:20:01
  End time: 30-Jul-2019 00:21:20
  Elapsed time: 1 min 19 secs
  Priority: 10
  FD Files Written: 1,702
  SD Files Written: 1,702
  FD Bytes Written: 314,373,356 (314.3 MB)
  SD Bytes Written: 314,635,737 (314.6 MB)
  Rate: 3979.4 KB/s
  Software Compression: 57.3 % (lz4)
  VSS: no
  Encryption: no
  Accurate: no
  Volume name(s): Incremental-0038
  Volume Session Id: 86
  Volume Session Time: 1563781778
  Last Volume Bytes: 315,005,362 (315.0 MB)
  Non-fatal FD errors: 0
  SD Errors: 0
  FD termination status: OK
  SD termination status: OK
  Bareos binary info: bareos.org build: Get official binaries and vendor support on bareos.com
  Termination: Backup OK

 2019-07-30 00:21:20 bareos-dir JobId 4187: Begin pruning Jobs older than 6 months .
 2019-07-30 00:21:20 bareos-dir JobId 4187: No Jobs found to prune.
 2019-07-30 00:21:20 bareos-dir JobId 4187: Begin pruning Files.
 2019-07-30 00:21:20 bareos-dir JobId 4187: Pruned Files from 1 Jobs for client vmlxgitlab01bs-fd from catalog.
 2019-07-30 00:21:20 bareos-dir JobId 4187: End auto prune.


--

do you see any reason for that error? i am confused why it could happen.

 2019-07-29 21:00:03 bareos-sd JobId 4185: Warning: stored/mount.cc:270 Open device "FileStorage" (/var/lib/bareos/storage) Volume "Incremental-0163" failed: ERR=stored/dev.cc:731 Could not open: /var/lib/bareos/storage/Incremental-0163, ERR=No such file or directory
arogge

arogge

2019-07-31 09:40

developer   ~0003538

The error is obvious: the file bareos wants to use does not exist. While the volume is still in the catalog it does not exist on disk.

Concerning the mismatching size for the volume: I guess you have found a (minor) bug.
The SelfTest job does Recycle the volume, but does not write to it (because there are no files to backup).
This means the Volume has been truncated and relabeled on disk (by the recycle step) but its catalog information has not been updated (because the job did not write to it).

Is that the same behaviour you're seeing every night?
Schroeffu

Schroeffu

2019-07-31 10:54

reporter   ~0003541

Thank you very much for the explanation. Make sense. Yes exactly, this is the same behaviour i get ervery night.

For an example and comparison, below one of the alerts I got in the middle of june already:

(Subject: Bareos: Backup OK of bareos-fd Incremental)
18-Jun 21:00 bareos-sd JobId 3689: Warning: Volume "Incremental-0006" not on device "FileStorage" (/var/lib/bareos/storage).
18-Jun 21:00 bareos-sd JobId 3689: Warning: Volume "Incremental-0006" not on device "FileStorage" (/var/lib/bareos/storage).
18-Jun 21:00 bareos-sd JobId 3689: Warning: stored/mount.cc:270 Open device "FileStorage" (/var/lib/bareos/storage) Volume "Incremental-0006" failed: ERR=stored/dev.cc:731 Could not open: /var/lib/bareos/storage/Incremental-0006, ERR=No such file or directory

(Subject: Bareos: Backup OK of vmlxgitlab01bs-fd Incremental)
19-Jun 00:20 bareos-sd JobId 3691: Warning: For Volume "Incremental-0089":
The sizes do not match! Volume=1073737134 Catalog=641 Correcting Catalog
arogge

arogge

2019-07-31 15:53

developer   ~0003542

So the question is why are your volume files disapearing?
But I guess that's not a Bareos issue, do I'd like to close the Bug if it is OK with you.

Issue History

Date Modified Username Field Change
2019-07-22 11:19 Schroeffu New Issue
2019-07-22 11:29 Schroeffu Note Added: 0003516
2019-07-22 13:02 arogge Status new => feedback
2019-07-22 13:02 arogge Note Added: 0003518
2019-07-30 09:59 Schroeffu Note Added: 0003533
2019-07-30 09:59 Schroeffu Status feedback => new
2019-07-31 09:40 arogge Status new => feedback
2019-07-31 09:40 arogge Note Added: 0003538
2019-07-31 10:54 Schroeffu Note Added: 0003541
2019-07-31 10:54 Schroeffu Status feedback => new
2019-07-31 15:53 arogge Status new => feedback
2019-07-31 15:53 arogge Note Added: 0003542