we are using Bacula on a Linux 2.6.18-238.5.1.el5PAE system, and have a Dell TL-2000 two drives (dev/nst0 and dev/nst1) autochanger. Bacula runs fine but we always encounter a tape error writing final EOF when using drive 1. There is an error message regarding the tape EOF, the tape does not fill up, bacula mounts the next tape, and continues the backup. The job finishes correctly. What is noticeable is that a part of the error message is identical (dev.c:1745 ioctl) and the error seems to appears at the same block (c:577) for 2 different tapes as shown below. The amount of data written to each tape varies before the error happening. I do not know if it makes a difference but just wanted to mention it. What could be the cause of this problem ? below are the logs:
EOF error on tape 0015MEL5: 08-May 03:00 saver.engr-dir JobId 213: Start Backup JobId 213, Job=saver-me.2011-05-08_03.00.01_15 08-May 03:00 saver.engr-dir JobId 213: Using Device "Drive-1" 08-May 02:58 saver-me-fd JobId 213: DIR and FD clocks differ by -65 seconds, FD automatically compensating. 08-May 02:58 saver-me-sd JobId 213: Spooling data ... 08-May 02:58 saver-me-sd JobId 213: Job write elapsed time = 00:00:01, Transfer rate = 157.0 K Bytes/second 08-May 02:58 saver-me-sd JobId 213: Committing spooled data to Volume "0015MEL5". Despooling 157,763 bytes ... 08-May 02:58 saver-me-sd JobId 213: Error: block.c:577 Write error at 10:1 on device "Drive-1" (/dev/nst1). ERR=Input/output error. 08-May 02:58 saver-me-sd JobId 213: Error: Error writing final EOF to tape. This Volume may not be readable. dev.c:1745 ioctl MTWEOF error on "Drive-1" (/dev/nst1). ERR=Input/output error. 08-May 02:58 saver-me-sd JobId 213: End of medium on Volume "0015MEL5" Bytes=5,504,034,816 Blocks=85,317 at 08-May-2011 02:58. 08-May 02:58 saver-me-sd JobId 213: 3307 Issuing autochanger "unload slot 15, drive 1" command. 08-May 03:04 saver-me-sd JobId 213: 3301 Issuing autochanger "loaded? drive 1" command. 08-May 03:04 saver-me-sd JobId 213: 3302 Autochanger "loaded? drive 1", result: nothing loaded. 08-May 03:04 saver-me-sd JobId 213: 3304 Issuing autochanger "load slot 16, drive 1" command. 08-May 03:05 saver-me-sd JobId 213: 3305 Autochanger "load slot 16, drive 1", status is OK. 08-May 03:05 saver-me-sd JobId 213: Wrote label to prelabeled Volume "0016MEL5" on device "Drive-1" (/dev/nst1) 08-May 03:05 saver-me-sd JobId 213: New volume "0016MEL5" mounted on device "Drive-1" (/dev/nst1) at 08-May-2011 03:05. 08-May 03:05 saver-me-sd JobId 213: Despooling elapsed time = 00:00:01, Transfer rate = 157.7 K Bytes/second 08-May 03:05 saver-me-sd JobId 213: Sending spooled attrs to the Director. Despooling 462 bytes ... 08-May 03:06 saver.engr-dir JobId 213: Bacula saver.engr-dir 5.0.3 (30Aug10): 08-May-2011 03:06:20 EOF error on tape 0016MEL5: 09-May 03:00 saver.engr-dir JobId 225: Start Backup JobId 225, Job=guss.2011-05-09_03.00.01_10 09-May 03:00 saver.engr-dir JobId 225: Using Device "Drive-1" 09-May 02:58 saver-me-sd JobId 225: Spooling data ... 09-May 03:00 guss-fd JobId 225: Generate VSS snapshots. Driver="VSS WinXP", Drive(s)="C" 09-May 03:00 guss-fd JobId 225: VSS Writer (BackupComplete): "MSDEWriter", State: 0x1 (VSS_WS_STABLE) 09-May 02:59 saver-me-sd JobId 225: Job write elapsed time = 00:00:17, Transfer rate = 6.654 M Bytes/second 09-May 03:00 guss-fd JobId 225: VSS Writer (BackupComplete): "Microsoft Writer (Bootable State)", State: 0x1 (VSS_WS_STABLE) 09-May 02:59 saver-me-sd JobId 225: Committing spooled data to Volume "0016MEL5". Despooling 113,227,156 bytes ... 09-May 03:00 guss-fd JobId 225: VSS Writer (BackupComplete): "Microsoft Writer (Service State)", State: 0x1 (VSS_WS_STABLE) 09-May 03:00 guss-fd JobId 225: VSS Writer (BackupComplete): "WMI Writer", State: 0x1 (VSS_WS_STABLE) 09-May 02:59 saver-me-sd JobId 225: Error: block.c:577 Write error at 4:3 on device "Drive-1" (/dev/nst1). ERR=Input/output error. 09-May 02:59 saver-me-sd JobId 225: Error: Error writing final EOF to tape. This Volume may not be readable. dev.c:1745 ioctl MTWEOF error on "Drive-1" (/dev/nst1). ERR=Input/output error. 09-May 02:59 saver-me-sd JobId 225: End of medium on Volume "0016MEL5" Bytes=2,538,805,248 Blocks=39,353 at 09-May-2011 02:59. 09-May 02:59 saver-me-sd JobId 225: 3307 Issuing autochanger "unload slot 16, drive 1" command. 09-May 03:04 saver-me-sd JobId 225: 3301 Issuing autochanger "loaded? drive 1" command. 09-May 03:04 saver-me-sd JobId 225: 3302 Autochanger "loaded? drive 1", result: nothing loaded. 09-May 03:04 saver-me-sd JobId 225: 3304 Issuing autochanger "load slot 17, drive 1" command. 09-May 03:05 saver-me-sd JobId 225: 3305 Autochanger "load slot 17, drive 1", status is OK. 09-May 03:05 saver-me-sd JobId 225: Wrote label to prelabeled Volume "0017MEL5" on device "Drive-1" (/dev/nst1) 09-May 03:05 saver-me-sd JobId 225: New volume "0017MEL5" mounted on device "Drive-1" (/dev/nst1) at 09-May-2011 03:05. 09-May 03:05 saver-me-sd JobId 225: Despooling elapsed time = 00:00:01, Transfer rate = 113.2 M Bytes/second 09-May 03:05 saver-me-sd JobId 225: Sending spooled attrs to the Director. Despooling 1,516 bytes ... 09-May 03:06 saver.engr-dir JobId 225: Bacula backup.engr.ucsb.edu-dir 5.0.3 (30Aug10): 09-May-2011 03:06:32 +---------------------------------------------------------------------- |This was sent by lwein...@yahoo.com via Backup Central. |Forward SPAM to ab...@backupcentral.com. +---------------------------------------------------------------------- ------------------------------------------------------------------------------ WhatsUp Gold - Download Free Network Management Software The most intuitive, comprehensive, and cost-effective network management toolset available today. Delivers lowest initial acquisition cost and overall TCO of any competing solution. http://p.sf.net/sfu/whatsupgold-sd _______________________________________________ Bacula-users mailing list Bacula-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/bacula-users
