Re: [Bacula-users] general question to robocopy and bacula

Kern Sibbald Fri, 19 Dec 2014 13:04:30 -0800

Hello,

This "error" doesn't look too serious to me, but it is also not normal behavior. Bacula is writing until it gets a bad status, which it does when it reports "got -1". That should happen when it hits the end of tape marker. Normally there is still plenty of room on the tape to write additional records before running into the physical end of tape. In your case Bacula gets an error trying to write and end of file mark. That means that either your tape drive does not have end of tape marker (positioned well before the end of the physical tape), or that you have a a Device resource that is not appropriate for your drive. This problem should have been examined and corrected when you ran the btape "test" command or at least when you used the "fill" command. Maybe you did not run these commands? They are recommended in the manual.

Anyway, the only way to know for sure if your tape is good is to read back all the data in the last block and ensure that it is valid.

Best regards,
Kern

On 12/19/2014 09:25 AM, Markus Rosjat wrote:

Here is a log from a backup that run yesterday, it tells me it was okay but when you take a look at the log it always tells that ther is a error befor he changes tape.

18-Dec 11:49 fg-back-dir JobId 11002: Start Backup JobId 11002, Job=ArbeitsdatenExtern.2014-12-18_11.36.25_35
18-Dec 11:49 fg-back-sd JobId 11002: 3307 Issuing autochanger "unload slot 6, drive 0" command.
18-Dec 11:51 fg-back-dir JobId 11002: Recycled volume "000131L3"
18-Dec 11:51 fg-back-dir JobId 11002: Using Device "LTO3"
18-Dec 11:51 fg-back-sd JobId 11002: 3301 Issuing autochanger "loaded? drive 0" command.
18-Dec 11:52 fg-back-sd JobId 11002: 3302 Autochanger "loaded? drive 0", result: nothing loaded.
18-Dec 11:52 fg-back-sd JobId 11002: 3304 Issuing autochanger "load slot 8, drive 0" command.
18-Dec 11:54 fg-back-sd JobId 11002: 3305 Autochanger "load slot 8, drive 0", status is OK.
18-Dec 11:54 fg-back-sd JobId 11002: Recycled volume "000131L3" on device "LTO3" (Tape0), all previous data lost.
18-Dec 11:54 fg-back-fd JobId 11002: Generate VSS snapshots. Driver="VSS Win 2003", Drive(s)="C"
18-Dec 15:09 fg-back-sd JobId 11002: End of Volume "000131L3" at 282:8348 on device "LTO3" (Tape0). Write of 64512 bytes got -1.
18-Dec 15:09 fg-back-sd JobId 11002: Error: Error writing final EOF to tape. This Volume may not be readable.
/home/kern/bacula/k/bacula/src/stored/dev.c:1723 ioctl MTWEOF error on "LTO3" (Tape0). ERR=Input/output error.
18-Dec 15:09 fg-back-sd JobId 11002: End of medium on Volume "000131L3" Bytes=282,520,498,176 Blocks=4,379,347 at 18-Dec-2014 15:09.
18-Dec 15:09 fg-back-sd JobId 11002: 3307 Issuing autochanger "unload slot 8, drive 0" command.
18-Dec 15:11 fg-back-dir JobId 11002: Recycled volume "JNR194L1"
18-Dec 15:11 fg-back-sd JobId 11002: 3301 Issuing autochanger "loaded? drive 0" command.
18-Dec 15:12 fg-back-sd JobId 11002: 3302 Autochanger "loaded? drive 0", result: nothing loaded.
18-Dec 15:12 fg-back-sd JobId 11002: 3304 Issuing autochanger "load slot 4, drive 0" command.
18-Dec 15:13 fg-back-sd JobId 11002: 3305 Autochanger "load slot 4, drive 0", status is OK.
18-Dec 15:13 fg-back-sd JobId 11002: Recycled volume "JNR194L1" on device "LTO3" (Tape0), all previous data lost.
18-Dec 15:13 fg-back-sd JobId 11002: New volume "JNR194L1" mounted on device "LTO3" (Tape0) at 18-Dec-2014 15:13.
18-Dec 17:56 fg-back-sd JobId 11002: End of Volume "JNR194L1" at 239:4082 on device "LTO3" (Tape0). Write of 64512 bytes got -1.
18-Dec 17:56 fg-back-sd JobId 11002: Error: Error writing final EOF to tape. This Volume may not be readable.
/home/kern/bacula/k/bacula/src/stored/dev.c:1723 ioctl MTWEOF error on "LTO3" (Tape0). ERR=Input/output error.
18-Dec 17:56 fg-back-sd JobId 11002: End of medium on Volume "JNR194L1" Bytes=239,248,041,984 Blocks=3,708,581 at 18-Dec-2014 17:56.
18-Dec 17:56 fg-back-sd JobId 11002: 3307 Issuing autochanger "unload slot 4, drive 0" command.
18-Dec 17:57 fg-back-dir JobId 11002: Recycled volume "RVME08L3"
18-Dec 17:57 fg-back-dir JobId 11002: Using Volume "RVME08L3" from 'Scratch' pool.
18-Dec 17:57 fg-back-sd JobId 11002: 3301 Issuing autochanger "loaded? drive 0" command.
18-Dec 17:58 fg-back-sd JobId 11002: 3302 Autochanger "loaded? drive 0", result: nothing loaded.
18-Dec 17:58 fg-back-sd JobId 11002: 3304 Issuing autochanger "load slot 5, drive 0" command.
18-Dec 18:00 fg-back-sd JobId 11002: 3305 Autochanger "load slot 5, drive 0", status is OK.
18-Dec 18:00 fg-back-sd JobId 11002: Recycled volume "RVME08L3" on device "LTO3" (Tape0), all previous data lost.
18-Dec 18:00 fg-back-sd JobId 11002: New volume "RVME08L3" mounted on device "LTO3" (Tape0) at 18-Dec-2014 18:00.
18-Dec 21:06 fg-back-sd JobId 11002: End of Volume "RVME08L3" at 257:8054 on device "LTO3" (Tape0). Write of 64512 bytes got -1.
18-Dec 21:06 fg-back-sd JobId 11002: Error: Error writing final EOF to tape. This Volume may not be readable.
/home/kern/bacula/k/bacula/src/stored/dev.c:1723 ioctl MTWEOF error on "LTO3" (Tape0). ERR=Input/output error.
18-Dec 21:06 fg-back-sd JobId 11002: End of medium on Volume "RVME08L3" Bytes=257,503,131,648 Blocks=3,991,553 at 18-Dec-2014 21:06.
18-Dec 21:06 fg-back-sd JobId 11002: 3307 Issuing autochanger "unload slot 5, drive 0" command.
18-Dec 21:07 fg-back-dir JobId 11002: Recycled volume "ADTE16L3"
18-Dec 21:07 fg-back-dir JobId 11002: Using Volume "ADTE16L3" from 'Scratch' pool.
18-Dec 21:07 fg-back-sd JobId 11002: 3301 Issuing autochanger "loaded? drive 0" command.
18-Dec 21:08 fg-back-sd JobId 11002: 3302 Autochanger "loaded? drive 0", result: nothing loaded.
18-Dec 21:08 fg-back-sd JobId 11002: 3304 Issuing autochanger "load slot 7, drive 0" command.
18-Dec 21:10 fg-back-sd JobId 11002: 3305 Autochanger "load slot 7, drive 0", status is OK.
18-Dec 21:10 fg-back-sd JobId 11002: Recycled volume "ADTE16L3" on device "LTO3" (Tape0), all previous data lost.
18-Dec 21:10 fg-back-sd JobId 11002: New volume "ADTE16L3" mounted on device "LTO3" (Tape0) at 18-Dec-2014 21:10.
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "System Writer", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-sd JobId 11002: Job write elapsed time = 12:11:46, Transfer rate = 22.94 M bytes/second
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "Registry Writer", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "COM+ REGDB Writer", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "MSDEWriter", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "Event Log Writer", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-fd JobId 11002: VSS Writer (BackupComplete): "WMI Writer", State: 0x1 (VSS_WS_STABLE)
19-Dec 00:18 fg-back-sd JobId 11002: Alert: TapeAlert[25]:Undefined.
19-Dec 00:18 fg-back-dir JobId 11002: Bacula fg-back-dir 3.0.3 (18Oct09): 19-Dec-2014 00:18:28
  Build OS:               Linux Cross-compile Win32
  JobId:                  11002
  Job:                    ArbeitsdatenExtern.2014-12-18_11.36.25_35
  Backup Level:           Full
  Client:                 "fg-back-fd" 3.0.3 (18Oct09) Linux,Cross-compile,Win32
  FileSet:                "ArbeitsdatenExtern" 2014-08-02 04:00:00
  Pool:                   "Extern" (From Job resource)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "LTO3" (From Job resource)
  Scheduled time:         18-Dec-2014 11:36:19
  Start time:             18-Dec-2014 11:51:23
  End time:               19-Dec-2014 00:18:28
  Elapsed time:           12 hours 27 mins 5 secs
  Priority:               3
  FD Files Written:       756,015
  SD Files Written:       756,015
  FD Bytes Written:       1,007,421,279,606 (1.007 TB)
  SD Bytes Written:       1,007,608,660,772 (1.007 TB)
  Rate:                   22474.5 KB/s
  Software Compression:   None
  VSS:                    yes
  Encryption:             no
  Accurate:               no
  Volume name(s):         000131L3|JNR194L1|RVME08L3|ADTE16L3
  Volume Session Id:      8
  Volume Session Time:    1418763182
  Last Volume Bytes:      228,946,701,312 (228.9 GB)
  Non-fatal FD errors:    0
  SD Errors:              3
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK -- with warnings


19-Dec 00:18 fg-back-dir JobId 11002: Begin pruning Jobs.
19-Dec 00:18 fg-back-dir JobId 11002: Pruned 1 Job for client fg-back-fd from catalog.
19-Dec 00:18 fg-back-dir JobId 11002: Begin pruning Files.
19-Dec 00:18 fg-back-dir JobId 11002: Pruned Files from 1 Jobs for client fg-back-fd from catalog.
19-Dec 00:18 fg-back-dir JobId 11002: End auto prune.

regards

Am 18.12.2014 um 16:16 schrieb Markus Rosjat:

Thx for the replies,

well the strange thing is that bacula started to throw errors around and 
stoped writing on the whole tape space. so I get backup where 500GB 
tapes written with 150gb but bacula errors that it reached endo of 
medium. I changed autoloader too but problem still exists. I was 
suspecting a faulty bacula database but no one could really verify this.

regards

Markus

Am 17.12.2014 um 16:15 schrieb Richard Fox:

Hi,

I'm sorry, I responded too soon. I'm not in fact, using robocopy 
(presumably on Windows?). I'm using rsync on Linux.

Thanks,
Rich.

On Wed, 17 Dec 2014, Richard Fox wrote:

Hi,

No, it shouldn't fail. I'm backing up a filesystem in which that very 
situation is happening. It completed fine twice last night while data 
was still streaming in.

Thanks,
Rich.

On Wed, 17 Dec 2014, Markus Rosjat wrote:

Hello List,

my simple question is:

If I have data that gets copied from a remote location to the
bacupserver with robocopy and bacula is running a job on the directory
while robocopy is changing it could that cause bacula to fail the job
with an r/w error ?

regards

-- 
Markus Rosjat    fon: +49 351 8107223    mail: ros...@ghweb.de

G+H Webservice GbR Gorzolla, Herrmann
Königsbrücker Str. 70, 01099 Dresden

http://www.ghweb.de
fon: +49 351 8107220   fax: +49 351 8107227

Bitte prüfen Sie, ob diese Mail wirklich ausgedruckt werden muss! Before you print it, think about your responsibility and commitment to the ENVIRONMENT

------------------------------------------------------------------------------
Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server
from Actuate! Instantly Supercharge Your Business Reports and Dashboards
with Interactivity, Sharing, Native Excel Exports, App Integration & more
Get technology previously reserved for billion-dollar corporations, FREE
http://pubads.g.doubleclick.net/gampad/clk?id=164703151&iu=/4140/ostg.clktrk

_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

------------------------------------------------------------------------------
Download BIRT iHub F-Type - The Free Enterprise-Grade BIRT Server
from Actuate! Instantly Supercharge Your Business Reports and Dashboards
with Interactivity, Sharing, Native Excel Exports, App Integration & more
Get technology previously reserved for billion-dollar corporations, FREE
http://pubads.g.doubleclick.net/gampad/clk?id=164703151&iu=/4140/ostg.clktrk

_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Re: [Bacula-users] general question to robocopy and bacula

Reply via email to