Marking Volume in Error in Catalog.

818 views
Skip to first unread message

Sébastien WENSKE

unread,
Sep 15, 2015, 4:02:31 AM9/15/15
to bareos-users
Hi group,

I have some troubles with volumes which are marked in error in the catalog and the associated file is no more on the file system.

Ragarding the log file, it seems that the volume is not labeled:


08-Aug 23:00 pc-backup2-dir JobId 269: Max configured use duration=86,400 sec. exceeded. Marking Volume "DailyDbSnap-Full-2015-08-07-1" as Used.
08-Aug 23:00 pc-backup2-dir JobId 269: Created new Volume "DailyDbSnap-Full-2015-08-08-2" in catalog.
08-Aug 23:00 pc-backup2-sd JobId 269: Volume "DailyDbSnap-Full-2015-08-08-2" previously written, moving to end of data.
08-Aug 23:00 pc-backup2-sd JobId 269: Warning: For Volume "DailyDbSnap-Full-2015-08-08-2":
The sizes do not match! Volume=80608089786 Catalog=0
Correcting Catalog
[Job OK]
[Next Job]
08-Aug 23:00 pc-backup2-sd JobId 268: Warning: Volume "DailyDbSnap-Full-2015-08-08-2" not on device "dbsnap" (/mnt/space2/bareos/storage/).
08-Aug 23:00 pc-backup2-sd JobId 268: Marking Volume "DailyDbSnap-Full-2015-08-08-2" in Error in Catalog.
08-Aug 23:00 pc-backup2-dir JobId 268: Created new Volume "DailyDbSnap-Full-2015-08-08-3" in catalog.
08-Aug 23:00 pc-backup2-sd JobId 268: Labeled new Volume "DailyDbSnap-Full-2015-08-08-3" on device "dbsnap" (/mnt/space2/bareos/storage/).
08-Aug 23:00 pc-backup2-sd JobId 268: Wrote label to prelabeled Volume "DailyDbSnap-Full-2015-08-08-3" on device "dbsnap" (/mnt/space2/bareos/storage/)


10-Aug 04:00 pc-backup2-dir JobId 547: Max configured use duration=86,400 sec. exceeded. Marking Volume "Binlog-Full-2015-08-09-4" as Used.
10-Aug 04:00 pc-backup2-dir JobId 547: Created new Volume "Binlog-Full-2015-08-10-5" in catalog.
10-Aug 04:00 pc-backup2-sd JobId 547: Volume "Binlog-Full-2015-08-10-5" previously written, moving to end of data.
10-Aug 04:00 pc-backup2-sd JobId 547: Warning: For Volume "Binlog-Full-2015-08-10-5":
The sizes do not match! Volume=7755019358 Catalog=0
Correcting Catalog
[Job OK]
[Next Job]
10-Aug 04:00 pc-backup2-sd JobId 548: Warning: Volume "Binlog-Full-2015-08-10-5" not on device "binlog" (/mnt/space2/bareos/storage/).
10-Aug 04:00 pc-backup2-sd JobId 548: Marking Volume "Binlog-Full-2015-08-10-5" in Error in Catalog.
10-Aug 04:00 pc-backup2-dir JobId 548: Created new Volume "Binlog-Full-2015-08-10-6" in catalog.
10-Aug 04:00 pc-backup2-sd JobId 548: Labeled new Volume "Binlog-Full-2015-08-10-6" on device "binlog" (/mnt/space2/bareos/storage/).
10-Aug 04:00 pc-backup2-sd JobId 548: Wrote label to prelabeled Volume "Binlog-Full-2015-08-10-6" on device "binlog" (/mnt/space2/bareos/storage/)

How can I fix this?

Best Regards,
Sebastien WENSKE

Philipp Storz

unread,
Sep 15, 2015, 4:10:07 AM9/15/15
to bareos...@googlegroups.com
If you have deleted the volume from the filesystem, you also need to remove it from the catalog db
with "delete"

e.g. delete volume=VOLNAME

Am 15.09.2015 10:02, schrieb Sébastien WENSKE:
> I have some troubles with volumes which are marked in error in the catalog and the associated file is no more on the file system.


--
Mit freundlichen Grüßen

Philipp Storz philip...@bareos.com
Bareos GmbH & Co. KG Phone: +49 221 63 06 93-92
http://www.bareos.com Fax: +49 221 63 06 93-10

Sitz der Gesellschaft: Köln | Amtsgericht Köln: HRA 29646
Geschäftsführer: Stephan Dühr, M. Außendorf,
J. Steffens, P. Storz, M. v. Wieringen

Sébastien WENSKE

unread,
Sep 15, 2015, 4:51:22 AM9/15/15
to bareos-users

> If you have deleted the volume from the filesystem, you also need to remove it from the catalog db
> with "delete"
>
> e.g. delete volume=VOLNAME
>

I don't delete the file, it seems not exists after (and may be before?) that the volume is marked as Error.

Regarding the log,
1- Bareos starts a job
2- Bareos create a new volume "DailyDbSnap-Full-2015-08-08-2" in catalog (sql)
3- The sizes do not match! (??) Correcting Catalog
4- Job result OK
5- Next Job: Warning: Volume "DailyDbSnap-Full-2015-08-08-2" not on device
6- Marking Volume "DailyDbSnap-Full-2015-08-08-2" in Error in Catalog.
7- Creating a new volume "DailyDbSnap-Full-2015-08-08-3"
8- Labeling new Volume "DailyDbSnap-Full-2015-08-08-3" <<- why the previous volume was not labaled in step 3??
9- Job OK

After that, the file associated to the "bad" volume is missing from the FS. I loose the content from the first Job.


I hope this is much clear about the issue.

Thanks,
Sebastien W


Marco Weiß

unread,
Sep 23, 2015, 10:21:22 AM9/23/15
to bareos-users
Hi Sébastien,

is the volume file physical on that directory?
/mnt/space2/bareos/storage/

It seems that Bareos will load a file thats not in that pool or it can not read and write to it...

First do you made changes to your pool/device configuration?

Second, regarding to you path /mnt/space2/bareos/storage/ i think you are mounting an external storage there?
If you mounted that storage with an other user than bareos maybe you have permission problems on that files. If the storage is mounted by NFS/SMB or other protocols you can check if the remote storage server blocks reading and writing to your tapes.

Regards,
Marco

Sébastien WENSKE

unread,
Sep 24, 2015, 3:05:40 AM9/24/15
to bareos-users
Hello Marco,

Yes the volume file should be in this directory like all others.

We have created our pools and devices.

/mnt/space2/bareos/storage/ is a local storage, and the user bareos have full acces to it.

this behaviour seems to be completly random...

Thanks,
Sebastien

Sébastien WENSKE

unread,
Sep 28, 2015, 4:33:52 AM9/28/15
to bareos-users
It happen again today: "28-Sep 04:00 pc-backup2-sd JobId 7899: Marking Volume "Binlog-Full-0717" in Error in Catalog."

this volume was created the septembre 19:

19-Sep 04:00 pc-backup2-dir JobId 6452: Start Backup JobId 6452, Job=pc-db11-4-MysqlBinlog.2015-09-19_04.00.00_27
19-Sep 04:00 pc-backup2-dir JobId 6452: Max configured use duration=86,400 sec. exceeded. Marking Volume "Binlog-Full-0629" as Used.
19-Sep 04:00 pc-backup2-dir JobId 6452: There are no more Jobs associated with Volume "Binlog-Full-2015-09-17-3". Marking it purged.
19-Sep 04:00 pc-backup2-dir JobId 6452: All records pruned from Volume "Binlog-Full-2015-09-17-3"; marking it "Purged"
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0708" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0709" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0710" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0711" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0712" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0713" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0714" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0715" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0716" in catalog.
>>> 19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0717" in catalog. <<<
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0718" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0719" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0720" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0721" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0722" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0723" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0724" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0725" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Created new Volume "Binlog-Full-0726" in catalog.
19-Sep 04:00 pc-backup2-dir JobId 6452: Using Device "binlog" to write.
19-Sep 04:32 pc-backup2-sd JobId 6452: Elapsed time=00:32:12, Transfer rate=3.492 M Bytes/second
19-Sep 04:32 pc-backup2-sd JobId 6452: Sending spooled attrs to the Director. Despooling 205,764 bytes ...
19-Sep 04:32 pc-backup2-dir JobId 6452: Bareos pc-backup2-dir 14.2.2 (12Dec14):
Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 7.0 (wheezy)


(if someone have an idea about why bareos create 19 volumes, please answer here https://groups.google.com/forum/?hl=fr#!topic/bareos-users/bk3lQAJZEEo thanks)

Then the volume (Binlog-Full-0717) is used by the JobId 7897. Again, the volume was not labeled by Bareos (??) but je Job ended successfully:

28-Sep 04:00 pc-backup2-dir JobId 7897: Start Backup JobId 7897, Job=pc-db13-2-MysqlBinlog.2015-09-28_04.00.00_31
28-Sep 04:00 pc-backup2-dir JobId 7897: Using Device "binlog" to write.
28-Sep 04:00 pc-backup2-dir JobId 7897: Max configured use duration=86,400 sec. exceeded. Marking Volume "Binlog-Full-0716" as Used.
28-Sep 04:00 pc-backup2-sd JobId 7897: Volume "Binlog-Full-0717" previously written, moving to end of data.
28-Sep 04:00 pc-backup2-sd JobId 7897: Warning: For Volume "Binlog-Full-0717":
The sizes do not match! Volume=23088576715 Catalog=0
Correcting Catalog
28-Sep 04:27 pc-backup2-sd JobId 7897: Elapsed time=00:27:36, Transfer rate=4.492 M Bytes/second
28-Sep 04:27 pc-backup2-sd JobId 7897: Sending spooled attrs to the Director. Despooling 217,278 bytes ...
28-Sep 04:27 pc-backup2-dir JobId 7897: Bareos pc-backup2-dir 14.2.2 (12Dec14):
Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 7.0 (wheezy)
JobId: 7897
Job: pc-db13-2-MysqlBinlog.2015-09-28_04.00.00_31
Backup Level: Full
Client: "pc-db13-2" 14.2.2 (12Dec14) x86_64-pc-linux-gnu,debian,Debian GNU/Linux 7.0 (wheezy)
FileSet: "MysqlBinlogSpace1SrvSet" 2015-08-07 11:00:00
Pool: "Binlog-Full" (From Run Pool override)
Catalog: "MyCatalog" (From Client resource)
Storage: "binlog" (From Pool resource)
Scheduled time: 28-Sep-2015 04:00:00
Start time: 28-Sep-2015 04:00:00
End time: 28-Sep-2015 04:27:37
Elapsed time: 27 mins 37 secs
Priority: 10
FD Files Written: 653
SD Files Written: 653
FD Bytes Written: 7,438,958,203 (7.438 GB)
SD Bytes Written: 7,439,051,411 (7.439 GB)
Rate: 4489.4 KB/s
Software Compression: 80.0 % (gzip)
VSS: no
Encryption: no
Accurate: no
Volume name(s): Binlog-Full-0718
Volume Session Id: 5257
Volume Session Time: 1440750597
Last Volume Bytes: 21,545,085,583 (21.54 GB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK

28-Sep 04:27 pc-backup2-dir JobId 7897: Begin pruning Jobs older than 6 months .
28-Sep 04:27 pc-backup2-dir JobId 7897: No Jobs found to prune.
28-Sep 04:27 pc-backup2-dir JobId 7897: Begin pruning Files.
28-Sep 04:27 pc-backup2-dir JobId 7897: No Files found to prune.
28-Sep 04:27 pc-backup2-dir JobId 7897: End auto prune.


On the next job which use this volume, it marks it on Error and labeled a new volume:

28-Sep 04:00 pc-backup2-dir JobId 7899: Start Backup JobId 7899, Job=pc-db11-4-MysqlBinlog.2015-09-28_04.00.00_33
28-Sep 04:00 pc-backup2-dir JobId 7899: Using Device "binlog" to write.
28-Sep 04:00 pc-backup2-sd JobId 7899: Warning: Volume "Binlog-Full-0717" not on device "binlog" (/mnt/space2/bareos/storage/).
28-Sep 04:00 pc-backup2-sd JobId 7899: Marking Volume "Binlog-Full-0717" in Error in Catalog.
28-Sep 04:00 pc-backup2-sd JobId 7899: Labeled new Volume "Binlog-Full-0718" on device "binlog" (/mnt/space2/bareos/storage/).
28-Sep 04:00 pc-backup2-sd JobId 7899: Wrote label to prelabeled Volume "Binlog-Full-0718" on device "binlog" (/mnt/space2/bareos/storage/)
28-Sep 04:29 pc-backup2-sd JobId 7899: Elapsed time=00:29:15, Transfer rate=3.917 M Bytes/second
28-Sep 04:29 pc-backup2-sd JobId 7899: Sending spooled attrs to the Director. Despooling 215,663 bytes ...
28-Sep 04:29 pc-backup2-dir JobId 7899: Bareos pc-backup2-dir 14.2.2 (12Dec14):
Build OS: x86_64-pc-linux-gnu debian Debian GNU/Linux 7.0 (wheezy)
JobId: 7899
Job: pc-db11-4-MysqlBinlog.2015-09-28_04.00.00_33
Backup Level: Full
Client: "pc-db11-4" 14.2.2 (12Dec14) x86_64-pc-linux-gnu,debian,Debian GNU/Linux 7.0 (wheezy)
FileSet: "MysqlBinlogSpace1SrvSet" 2015-08-07 11:00:00
Pool: "Binlog-Full" (From Run Pool override)
Catalog: "MyCatalog" (From Client resource)
Storage: "binlog" (From Pool resource)
Scheduled time: 28-Sep-2015 04:00:00
Start time: 28-Sep-2015 04:00:01
End time: 28-Sep-2015 04:29:17
Elapsed time: 29 mins 16 secs
Priority: 10
FD Files Written: 654
SD Files Written: 654
FD Bytes Written: 6,874,277,735 (6.874 GB)
SD Bytes Written: 6,874,369,138 (6.874 GB)
Rate: 3914.7 KB/s
Software Compression: 84.9 % (gzip)
VSS: no
Encryption: no
Accurate: no
Volume name(s): Binlog-Full-0718
Volume Session Id: 5259
Volume Session Time: 1440750597
Last Volume Bytes: 22,355,888,618 (22.35 GB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK

28-Sep 04:29 pc-backup2-dir JobId 7899: Begin pruning Jobs older than 6 months .
28-Sep 04:29 pc-backup2-dir JobId 7899: No Jobs found to prune.
28-Sep 04:29 pc-backup2-dir JobId 7899: Begin pruning Files.
28-Sep 04:29 pc-backup2-dir JobId 7899: No Files found to prune.
28-Sep 04:29 pc-backup2-dir JobId 7899: End auto prune.


I can provide debug logs of sd and dir.


Best regards,
Sébastien W.





Reply all
Reply to author
Forward
0 new messages