I upgraded my SD to the svn code on the 27th of September and when
running a job today I got the following error:

Job queued. JobId=6954
01-Oct 15:49 fileserver-dir: Start Backup JobId 6954,
Job=HOLOGICArchive-Set2-Job.2007-10-01_15.49.02
01-Oct 15:49 fileserver-dir: Using Device "LTO2-0"
01-Oct 15:49 fileserver-dir:
HOLOGICArchive-Set2-Job.2007-10-01_15.49.02 Fatal error: Volume Files
at 170 being set to 73 for Volume "A00034". This is incorrect.
01-Oct 15:49 dev6-sd: HOLOGICArchive-Set2-Job.2007-10-01_15.49.02
Fatal error: Error getting Volume info: 1992 Update Media error.
VolFiles=73, CatFiles=170
01-Oct 15:49 dev6-sd: Job write elapsed time = 00:00:01, Transfer rate
= 0  bytes/second
01-Oct 15:50 fileserver-fd:
HOLOGICArchive-Set2-Job.2007-10-01_15.49.02 Fatal error: backup.c:892
Network send error to SD. ERR=Connection reset by peer
01-Oct 15:50 fileserver-dir:
HOLOGICArchive-Set2-Job.2007-10-01_15.49.02 Error: Bacula
fileserver-dir 2.2.4 (14Sep07): 01-Oct-2007 15:50:59
  Build OS:               x86_64-pc-linux-gnu gentoo
  JobId:                  6954
  Job:                    HOLOGICArchive-Set2-Job.2007-10-01_15.49.02
  Backup Level:           Full
  Client:                 "fileserver-fd" 2.2.4 (14Sep07)
x86_64-pc-linux-gnu,gentoo,
  FileSet:                "HologicArchive" 2006-11-03 14:26:07
  Pool:                   "LTO2-Archived-Data-Set2" (From Job resource)
  Storage:                "DEV6-Changer" (From Job resource)
  Scheduled time:         01-Oct-2007 15:48:51
  Start time:             01-Oct-2007 15:49:05
  End time:               01-Oct-2007 15:50:59
  Elapsed time:           1 min 54 secs
  Priority:               10
  FD Files Written:       1
  SD Files Written:       0
  FD Bytes Written:       131,072 (131.0 KB)
  SD Bytes Written:       0 (0 B)
  Rate:                   1.1 KB/s
  Software Compression:   33.3 %
  VSS:                    no
  Encryption:             no
  Volume name(s):         A00027
  Volume Session Id:      46
  Volume Session Time:    1190920190
  Last Volume Bytes:      72,647,608,320 (72.64 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  Error
  SD termination status:  Error
  Termination:            *** Backup Error ***


I find the "Volume Files at 170 being set to 73 for Volume "A00034".
This is incorrect." line very interesting.

The correct tape is A00027 which is in a different pool than A00034.
A00034 does indeed have 170 volume files but A00027 has 73. A00034 was
loaded but it appears there was no attempt to unload the tape and load
A00027.

After this I released the tape A00034 from the autochanger and now it
appears to want to use tape A00038 which again is not in the correct
pool:
Job queued. JobId=6955
01-Oct 16:02 fileserver-dir: Start Backup JobId 6955,
Job=HOLOGICArchive-Set2-Job.2007-10-01_16.02.22
01-Oct 16:02 fileserver-dir: Using Device "LTO2-1"
01-Oct 16:02 fileserver-dir:
HOLOGICArchive-Set2-Job.2007-10-01_16.02.22 Fatal error: Volume Files
at 121 being set to 73 for Volume "A00038". This is incorrect.
01-Oct 16:03 dev6-sd: HOLOGICArchive-Set2-Job.2007-10-01_16.02.22
Fatal error: Error getting Volume info: 1992 Update Media error.
VolFiles=73, CatFiles=121
01-Oct 16:03 dev6-sd: Job write elapsed time = 00:00:01, Transfer rate
= 0  bytes/second
  Build OS:               x86_64-pc-linux-gnu gentoo
  JobId:                  6955
  Job:                    HOLOGICArchive-Set2-Job.2007-10-01_16.02.22
  Backup Level:           Full
  Client:                 "fileserver-fd" 2.2.4 (14Sep07)
x86_64-pc-linux-gnu,gentoo,
  FileSet:                "HologicArchive" 2006-11-03 14:26:07
  Pool:                   "LTO2-Archived-Data-Set2" (From Job resource)
  Storage:                "DEV6-Changer" (From Job resource)
  Scheduled time:         01-Oct-2007 16:02:20
  Start time:             01-Oct-2007 16:02:25
  End time:               01-Oct-2007 16:03:17
  Elapsed time:           52 secs
  Priority:               10
  FD Files Written:       1
  SD Files Written:       0
  FD Bytes Written:       131,072 (131.0 KB)
  SD Bytes Written:       0 (0 B)
  Rate:                   2.5 KB/s
  Software Compression:   33.3 %
  VSS:                    no
  Encryption:             no
  Volume name(s):         A00027
  Volume Session Id:      47
  Volume Session Time:    1190920190
  Last Volume Bytes:      72,647,608,320 (72.64 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  Error
  SD termination status:  Error
  Termination:            *** Backup Error ***


After releasing the second tape. I tried to run the job yet again and
I got the following message:

Job queued. JobId=6956
01-Oct 16:08 fileserver-dir: Start Backup JobId 6956,
Job=HOLOGICArchive-Set2-Job.2007-10-01_16.08.40
01-Oct 16:08 fileserver-dir: Using Device "LTO2-0"
01-Oct 16:09 dev6-sd: Invalid slot=0 defined in catalog for Volume
"A00027" on "LTO2-0" (/dev/nst0). Manual load my be required.
01-Oct 16:09 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:09 dev6-sd: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
01-Oct 16:09 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:09 dev6-sd: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
01-Oct 16:09 dev6-sd: Invalid slot=0 defined in catalog for Volume
"A00027" on "LTO2-0" (/dev/nst0). Manual load my be required.
01-Oct 16:09 dev6-sd: Please mount Volume "A00027" or label a new one for:
    Job:          HOLOGICArchive-Set2-Job.2007-10-01_16.08.40
    Storage:      "LTO2-0" (/dev/nst0)
    Pool:         LTO2-Archived-Data-Set2
    Media type:   LTO-2


Is this because I did not do an update slots after restarting the
bacula-sd service?

After running update slots, it looks like all is well.

3001 OK mount. Device="LTO2-0" (/dev/nst0)
01-Oct 16:10 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:10 dev6-sd: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
01-Oct 16:10 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:10 dev6-sd: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
01-Oct 16:10 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:10 dev6-sd: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
01-Oct 16:10 dev6-sd: 3304 Issuing autochanger "load slot 21, drive 0" command.
01-Oct 16:12 dev6-sd: 3305 Autochanger "load slot 21, drive 0", status is OK.
01-Oct 16:12 dev6-sd: 3301 Issuing autochanger "loaded? drive 0" command.
01-Oct 16:12 dev6-sd: 3302 Autochanger "loaded? drive 0", result is Slot 21.
01-Oct 16:12 dev6-sd: Volume "A00027" previously written, moving to end of data.
#


John M. Drescher

-------------------------------------------------------------------------
This SF.net email is sponsored by: Microsoft
Defy all challenges. Microsoft(R) Visual Studio 2005.
http://clk.atdmt.com/MRT/go/vse0120000070mrt/direct/01/
_______________________________________________
Bacula-devel mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/bacula-devel

Reply via email to