On Wednesday, December 28, 2016 at 10:14:02 PM UTC+1, Robert N wrote: > Hi, > > I'm running Bareos 15.2.3 on centos 6. > > configured 60G spool size, but seems like bareos actually uses 1M and 2M > spoolsize. I'm not able to find a pattern, but also seen 7M and 8M spoolsizes. > > here are the messages from logs: > > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Spooling data ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Forward spacing Volume > "Incr-3618" to file:block 0:220. > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: User specified Device spool size > reached: DevSpoolSize=60,020,128,434 MaxDevSpoolSize=60,000,000,000 > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Writing spooled data to Volume. > Despooling 1,048,588 bytes ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Despooling elapsed time = > 00:00:01, Transfer rate = 1.048 M Bytes/second > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Spooling data again ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: User specified Device spool size > reached: DevSpoolSize=60,021,177,022 MaxDevSpoolSize=60,000,000,000 > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Writing spooled data to Volume. > Despooling 2,097,176 bytes ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Despooling elapsed time = > 00:00:02, Transfer rate = 1.048 M Bytes/second > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Spooling data again ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: User specified Device spool size > reached: DevSpoolSize=60,021,177,022 MaxDevSpoolSize=60,000,000,000 > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Writing spooled data to Volume. > Despooling 2,097,176 bytes ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Despooling elapsed time = > 00:00:01, Transfer rate = 2.097 M Bytes/second > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Spooling data again ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: User specified Device spool size > reached: DevSpoolSize=60,021,177,022 MaxDevSpoolSize=60,000,000,000 > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Writing spooled data to Volume. > Despooling 2,097,176 bytes ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Despooling elapsed time = > 00:00:01, Transfer rate = 2.097 M Bytes/second > > Some of the jobs fail after a while with the following errors: > > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Spooling data again ... > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: End of Volume at file 0 on > device "DiskDeviceIncr1" (/data/bareos-storage/Incr), Volume "Incr-3618" > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Ready to read from volume > "Incr-3621" on device "DiskDeviceIncr1" (/data/bareos-storage/Incr). > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Forward spacing Volume > "Incr-3621" to file:block 0:999959905. > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Error: block.c:286 Volume data > error at 0:999959905! Wanted ID: "BB02", got " al". Buffer discarded. > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Fatal error: mac.c:636 Fatal > append error on device "DriveDevice" (/dev/nst0): ERR= > 28-Dec 08:19 muc1pro-backup-1-sd JobId 9648: Elapsed time=00:00:14, Transfer > rate=20.81 M Bytes/second > 28-Dec 08:19 muc1pro-backup-1-dir JobId 9648: Error: bsock_tcp.c:422 Write > error sending 371 bytes to Storage > daemon:muc1pro-backup-1.adm.financial.com:9103: ERR=Broken pipe > > Before setting the spoolsize to 60GB, it was 512GB and didn't see > behavior/erros like these. the spooling process was either filling up to 512G > oder up to job size if less than 512GB. > > Any clues why the spooling doesn't work correctly? > > Thank you. > Robert
here some more details from another job + debug info: 28-Dec 23:07 muc1pro-backup-1-sd JobId 9813: Ready to read from volume "Incr-3874" on device "DiskDeviceIncr1" (/data/bareos-storage/Incr). 28-Dec 23:07 muc1pro-backup-1-sd JobId 9813: Forward spacing Volume "Incr-3874" to file:block 0:121089224. 28-Dec 23:07 muc1pro-backup-1-sd JobId 9813: Error: block.c:286 Volume data error at 0:121089224! Wanted ID: "BB02", got "×áÚp". Buffer discarded. 28-Dec 23:07 muc1pro-backup-1-sd JobId 9813: Fatal error: mac.c:636 Fatal append error on device "DriveDevice" (/dev/nst0): ERR= 28-Dec 23:07 muc1pro-backup-1-sd JobId 9813: Elapsed time=00:00:24, Transfer rate=249.9 M Bytes/second 28-Dec 23:07 muc1pro-backup-1-dir JobId 9813: Error: bsock_tcp.c:422 Write error sending 369 bytes to Storage daemon:muc1pro-backup-1.adm.financial.com:9103: ERR=Broken pipe 28-Dec 23:07 muc1pro-backup-1-dir JobId 9813: Error: Bareos muc1pro-backup-1-dir 15.2.3 and the debug: muc1pro-backup-1-sd (100): acquire.c:64-9813 MediaType dcr=FileIncr dev=FileIncr muc1pro-backup-1-sd (100): acquire.c:92-9813 Want Vol=Incr-3874 Slot=0 muc1pro-backup-1-sd (100): acquire.c:106-9813 MediaType dcr=FileIncr dev=FileIncr muc1pro-backup-1-sd (100): acquire.c:174-9813 MediaType dcr=FileIncr dev=FileIncr muc1pro-backup-1-sd (100): acquire.c:193-9813 dir_get_volume_info vol=Incr-3874 muc1pro-backup-1-sd (50): askdir.c:248-9813 >dird CatReq Job=CopyToTape.2016-12-28_23.07.17_30 GetVolInfo VolName=Incr-3874 write=0 muc1pro-backup-1-sd (50): askdir.c:177-9813 <dird 1000 OK VolName=Incr-3874 VolJobs=1 VolFiles=0 VolBlocks=31001 VolBytes=1999882588 VolMounts=2 VolErrors=0 VolWr ites=197443 MaxVolBytes=10737418240 VolCapacityBytes=0 VolStatus=Used Slot=0 MaxVolJobs=1 MaxVolFiles=0 InChanger=0 VolReadTime=103350 VolWriteTime=32620114 EndFi le=0 EndBlock=1999753563 LabelType=0 MediaId=3874 EncryptionKey= MinBlocksize=0 MaxBlocksize=0 muc1pro-backup-1-sd (50): askdir.c:213-9813 do_get_volume_info return true slot=0 Volume=Incr-3874, VolminBlocksize=0 VolMaxBlocksize=0 muc1pro-backup-1-sd (50): askdir.c:215-9813 setting dcr->VolMinBlocksize(0) to vol.VolMinBlocksize(0) muc1pro-backup-1-sd (50): askdir.c:217-9813 setting dcr->VolMaxBlocksize(0) to vol.VolMaxBlocksize(0) muc1pro-backup-1-sd (100): mount.c:650-9813 No swap_dev set muc1pro-backup-1-sd (100): mount.c:600-9813 Must load "DiskDeviceIncr1" (/data/bareos-storage/Incr) muc1pro-backup-1-sd (100): autochanger.c:99-9813 Device "DiskDeviceIncr1" (/data/bareos-storage/Incr) is not an autochanger muc1pro-backup-1-sd (100): acquire.c:235-9813 stored: open vol=Incr-3874 muc1pro-backup-1-sd (100): dev.c:561-9813 open dev: type=1 dev_name="DiskDeviceIncr1" (/data/bareos-storage/Incr) vol=Incr-3874 mode=OPEN_READ_ONLY muc1pro-backup-1-sd (100): dev.c:572-9813 call open_device mode=OPEN_READ_ONLY muc1pro-backup-1-sd (100): dev.c:646-9813 open disk: mode=OPEN_READ_ONLY open(/data/bareos-storage/Incr/Incr-3874, 0x0, 0640) muc1pro-backup-1-sd (100): dev.c:662-9813 open dev: disk fd=6 opened muc1pro-backup-1-sd (100): dev.c:580-9813 preserve=0x29ff57c0 fd=6 muc1pro-backup-1-sd (100): acquire.c:243-9813 opened dev "DiskDeviceIncr1" (/data/bareos-storage/Incr) OK muc1pro-backup-1-sd (100): acquire.c:257-9813 calling read-vol-label muc1pro-backup-1-sd (100): dev.c:502-9813 setting minblocksize to 64512, maxblocksize to label_block_size=64512, on device "DiskDeviceIncr1" (/data/bareos-storage /Incr) muc1pro-backup-1-sd (100): label.c:76-9813 Enter read_volume_label res=1 device="DiskDeviceIncr1" (/data/bareos-storage/Incr) vol=Incr-3874 dev_Vol=*NULL* max_blo cksize=64512 muc1pro-backup-1-sd (100): label.c:251-9813 Call reserve_volume=Incr-3874 muc1pro-backup-1-sd (100): dev.c:432-9813 Device "DiskDeviceIncr1" (/data/bareos-storage/Incr) has dev->device->max_block_size of 0 and dev->max_block_size of 645 12, dcr->VolMaxBlocksize is 0 muc1pro-backup-1-sd (100): dev.c:474-9813 set minblocksize to 64512, maxblocksize to 64512 on device "DiskDeviceIncr1" (/data/bareos-storage/Incr) muc1pro-backup-1-sd (100): acquire.c:263-9813 Got correct volume. muc1pro-backup-1-sd (100): acquire.c:370-9813 dcr=7f021012a9c8 dev=7f02240016d8 muc1pro-backup-1-sd (100): acquire.c:371-9813 MediaType dcr=FileIncr dev=FileIncr muc1pro-backup-1-sd (100): dev.c:892-9813 ===== lseek to 121089224 muc1pro-backup-1-sd (50): block.c:287-9813 block.c:286 Volume data error at 0:121089224! Wanted ID: "BB02", got "<D7><E1><DA>p". Buffer discarded. muc1pro-backup-1-sd (100): mac.c:629-9813 ok=0 muc1pro-backup-1-sd (100): mac.c:637-9813 Set ok=FALSE after write_block_to_device. muc1pro-backup-1-sd (100): spool.c:119-9813 Data spooling discarded muc1pro-backup-1-sd (100): spool.c:205-9813 Deleted spool file: /data/bareos-storage/spool/muc1pro-backup-1-sd.data.9813.CopyToTape.2016-12-28_23.07.17_30.DriveDevice.spool muc1pro-backup-1-sd (100): acquire.c:504-9813 release_device device "DriveDevice" (/dev/nst0) is tape muc1pro-backup-1-sd (100): acquire.c:528-9813 There are 0 writers in release_device muc1pro-backup-1-sd (50): askdir.c:366-9813 Update cat VolBytes=217 muc1pro-backup-1-sd (50): askdir.c:391-9813 >dird CatReq Job=CopyToTape.2016-12-28_23.07.17_30 UpdateMedia VolName=000019L6 VolJobs=31 VolFiles=1 VolBlocks=0 VolBytes=217 VolMounts=72 VolErrors=0 VolWrites=385987 MaxVolBytes=0 EndTime=1482962864 VolStatus=Append Slot=12 relabel=0 InChanger=1 VolReadTime=0 VolWriteTime=930001999 VolFirstWritten=0 muc1pro-backup-1-sd (100): acquire.c:568-9813 0 writers, 0 reserve, dev="DriveDevice" (/dev/nst0) muc1pro-backup-1-sd (100): dev.c:933-9813 close_dev "DriveDevice" (/dev/nst0) muc1pro-backup-1-sd (100): dev.c:1043-9813 Enter unmount muc1pro-backup-1-sd (100): dev.c:921-9813 Clear volhdr vol=000019L6 muc1pro-backup-1-sd (100): acquire.c:626-9813 JobId=9813 broadcast wait_device_release at 28-Dec-2016 23:07:44 muc1pro-backup-1-sd (100): acquire.c:648-9813 Device "DriveDevice" (/dev/nst0) released by JobId=9813 muc1pro-backup-1-sd (100): spool.c:823-9813 Close attr spool file at 28-Dec-2016 23:07:44 muc1pro-backup-1-sd (100): acquire.c:504-9813 release_device device "DiskDeviceIncr1" (/data/bareos-storage/Incr) is disk muc1pro-backup-1-sd (50): askdir.c:366-9813 Update cat VolBytes=1999882588 muc1pro-backup-1-sd (50): askdir.c:391-9813 >dird CatReq Job=CopyToTape.2016-12-28_23.07.17_30 UpdateMedia VolName=Incr-3874 VolJobs=1 VolFiles=0 VolBlocks=31001 VolBytes=1999882588 VolMounts=2 VolErrors=0 VolWrites=197443 MaxVolBytes=10737418240 EndTime=1482962864 VolStatus=Used Slot=0 relabel=0 InChanger=0 VolReadTime=103405 VolWriteTime=32620114 VolFirstWritten=0 muc1pro-backup-1-sd (100): acquire.c:568-9813 0 writers, 0 reserve, dev="DiskDeviceIncr1" (/data/bareos-storage/Incr) muc1pro-backup-1-sd (100): dev.c:933-9813 close_dev "DiskDeviceIncr1" (/data/bareos-storage/Incr) muc1pro-backup-1-sd (100): dev.c:1043-9813 Enter unmount muc1pro-backup-1-sd (100): dev.c:921-9813 Clear volhdr vol=Incr-3874 muc1pro-backup-1-sd (100): acquire.c:626-9813 JobId=9813 broadcast wait_device_release at 28-Dec-2016 23:07:44 muc1pro-backup-1-sd (100): acquire.c:648-9813 Device "DiskDeviceIncr1" (/data/bareos-storage/Incr) released by JobId=9813 muc1pro-backup-1-sd (30): mac.c:681-9813 Done reading. muc1pro-backup-1-sd (100): mac.c:691-9813 3099 Job CopyToTape.2016-12-28_23.07.17_30 end JobStatus=69 JobFiles=34277 JobBytes=5998087648 JobErrors=15223688 muc1pro-backup-1-sd (100): jcr.c:184-9813 write_last_jobs seek to 192 thanks, Robert -- You received this message because you are subscribed to the Google Groups "bareos-users" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. To post to this group, send email to [email protected]. For more options, visit https://groups.google.com/d/optout.
