Hi All,
For the past few months, I've had the following problem:
1. I run a series of jobs
2. The first job picks a volume and starts loading the first drive
3. One of the next few jobs wants to use the same volume as an
earlier job but on another drive
In the logs I include below, note in particular that the Device and
"In Use Volume" statuses differ in where they think the tapes are --
In fact the "In Use Volume" is wrong. Could this disconnect be the
cause of the problems I've been experiencing? Any idea where I should
go from here?
BTW, I updated to the latest 1.39.20 beta and while updating the
mysql tables, I got this error:
ERROR 1060 (42S21) at line 37: Duplicate column name 'MediaTypeId'
ERROR 1060 (42S21) at line 38: Duplicate column name 'DeviceId'
ERROR 1060 (42S21) at line 39: Duplicate column name 'LocationId'
ERROR 1060 (42S21) at line 40: Duplicate column name 'RecycleCount'
ERROR 1060 (42S21) at line 41: Duplicate column name 'InitialWrite'
ERROR 1060 (42S21) at line 42: Duplicate column name 'ScratchPoolId'
ERROR 1060 (42S21) at line 43: Duplicate column name 'RecyclePoolId'
ERROR 1060 (42S21) at line 44: Duplicate column name 'Enabled'
ERROR 1060 (42S21) at line 45: Duplicate column name 'Comment'
ERROR 1091 (42000) at line 47: Can't DROP 'Stripe'; check that
column/key exists
ERROR 1060 (42S21) at line 49: Duplicate column name 'PriorJobId'
ERROR 1060 (42S21) at line 50: Duplicate column name 'RealEndTime'
Update of Bacula MySQL tables succeeded.
Note that the problem I'm describing here was happening before this
update, but I do wonder if the update script was picking up on the
problem.
Here's the output from this month's full backup run:
06-Sep 22:18 sbgrid-dir: Start Backup JobId 534, Job=CRYSTAL_HOME.
2006-09-06_22.18.16
06-Sep 22:18 sbgrid-sd: 3301 Issuing autochanger "loaded drive 0"
command.
06-Sep 22:18 sbgrid-dir: Start Backup JobId 535, Job=FS3_PROGRAMS.
2006-09-06_22.18.20
06-Sep 22:18 sbgrid-sd: 3302 Autochanger "loaded drive 0", result:
nothing loaded.
06-Sep 22:18 sbgrid-sd: 3304 Issuing autochanger "load slot 6, drive
0" command.
06-Sep 22:18 sbgrid-dir: Start Backup JobId 536,
Job=EML1.2006-09-06_22.18.23
06-Sep 22:18 sbgrid-dir: Start Backup JobId 537,
Job=EML2.2006-09-06_22.18.26
06-Sep 22:18 sbgrid-dir: Start Backup JobId 538,
Job=EML3.2006-09-06_22.18.28
06-Sep 22:18 sbgrid-dir: Start Backup JobId 539,
Job=EML4.2006-09-06_22.18.31
06-Sep 22:18 sbgrid-sd: 3305 Autochanger "load slot 6, drive 0",
status is OK.
06-Sep 22:18 sbgrid-sd: 3301 Issuing autochanger "loaded drive 0"
command.
06-Sep 22:19 sbgrid-sd: 3302 Autochanger "loaded drive 0", result is
Slot 6.
06-Sep 22:19 sbgrid-sd: 3301 Issuing autochanger "loaded drive 2"
command.
06-Sep 22:19 sbgrid-sd: Volume "000044L2" previously written, moving
to end of data.
06-Sep 22:19 sbgrid-sd: 3302 Autochanger "loaded drive 2", result:
nothing loaded.
06-Sep 22:19 sbgrid-sd: 3301 Issuing autochanger "loaded drive 1"
command.
06-Sep 22:19 sbgrid-sd: Job EML1.2006-09-06_22.18.23 waiting to
reserve a device.
06-Sep 22:19 sbgrid-sd: 3302 Autochanger "loaded drive 1", result:
nothing loaded.
06-Sep 22:19 sbgrid-sd: 3304 Issuing autochanger "load slot 7, drive
1" command.
06-Sep 22:19 sbgrid-sd: 3305 Autochanger "load slot 7, drive 1",
status is OK.
06-Sep 22:19 sbgrid-sd: 3301 Issuing autochanger "loaded drive 1"
command.
06-Sep 22:19 sbgrid-sd: 3302 Autochanger "loaded drive 1", result is
Slot 7.
06-Sep 22:19 sbgrid-sd: Volume "000045L2" previously written, moving
to end of data.
06-Sep 22:19 sbgrid-sd: Ready to append to end of Volume "000044L2"
at file=219.
06-Sep 22:20 sbgrid-sd: Ready to append to end of Volume "000045L2"
at file=233.
06-Sep 22:34 sbgrid-sd: EML1.2006-09-06_22.18.23 Warning: Volume
"000044L2" is in use by device "LTO2A" (/dev/nst0)
06-Sep 22:34 sbgrid-sd: 3301 Issuing autochanger "loaded drive 2"
command.
06-Sep 22:34 sbgrid-sd: 3302 Autochanger "loaded drive 2", result:
nothing loaded.
06-Sep 22:34 sbgrid-sd: 3301 Issuing autochanger "loaded drive 2"
command.
06-Sep 22:34 sbgrid-sd: 3302 Autochanger "loaded drive 2", result:
nothing loaded.
06-Sep 22:34 sbgrid-sd: 3301 Issuing autochanger "loaded drive 2"
command.
06-Sep 22:34 sbgrid-sd: 3302 Autochanger "loaded drive 2", result:
nothing loaded.
06-Sep 22:34 sbgrid-sd: Job EML1.2006-09-06_22.18.23 waiting to
reserve a device.
And here's what the SD reports:
Running Jobs:
Writing: Full Backup job CRYSTAL_HOME JobId=534 Volume="000044L2"
pool="Fulls" device=""LTO2A" (/dev/nst0)"
Files=5,471 Bytes=761,713,085 Bytes/sec=11,201,663
FDReadSeqNo=54,284 in_msg=39854 out_msg=5 fd=8
Writing: Full Backup job FS3_PROGRAMS JobId=535 Volume="000045L2"
pool="Fulls" device=""LTO2B" (/dev/nst1)"
Files=870 Bytes=68,336,463 Bytes/sec=9,762,351
FDReadSeqNo=8,250 in_msg=5791 out_msg=5 fd=11
Writing: Full Backup job EML1 JobId=536 Volume="000044L2"
pool="Fulls" device=""LTO2C" (/dev/nst2)"
Files=0 Bytes=0 Bytes/sec=0
FDReadSeqNo=6 in_msg=6 out_msg=4 fd=9
Writing: Full Backup job EML2 JobId=537 Volume="000044L2"
pool="Fulls" device=""LTO2A" (/dev/nst0)"
Files=1 Bytes=1,395,392,617 Bytes/sec=20,520,479
FDReadSeqNo=21,303 in_msg=21301 out_msg=5 fd=13
Writing: Full Backup job EML3 JobId=538 Volume="000045L2"
pool="Fulls" device=""LTO2B" (/dev/nst1)"
Files=1,287 Bytes=74,738,314 Bytes/sec=10,676,902
FDReadSeqNo=11,537 in_msg=7693 out_msg=5 fd=15
Writing: Full Backup job EML4 JobId=539 Volume=""
pool="Fulls" device=""LTO2C" (/dev/nst2)"
Files=0 Bytes=0 Bytes/sec=0
FDReadSeqNo=6 in_msg=6 out_msg=4 fd=17
Device status:
Autochanger "ADIC Scalar 100" with devices:
"LTO2A" (/dev/nst0)
"LTO2B" (/dev/nst1)
"LTO2C" (/dev/nst2)
Device "FileStorage" (/tmp) is not open.
Device "LTO2A" (/dev/nst0) is mounted with Volume="000044L2"
Pool="Fulls"
Slot 6 is loaded in drive 0.
Total Bytes=220,653,540,065 Blocks=3,420,350 Bytes/block=64,511
Positioned at File=221 Block=2,464
Device "LTO2B" (/dev/nst1) is mounted with Volume="000045L2"
Pool="Fulls"
Slot 7 is loaded in drive 1.
Total Bytes=232,335,698,079 Blocks=3,601,436 Bytes/block=64,511
Positioned at File=233 Block=2,219
Device "LTO2C" (/dev/nst2) open but no Bacula volume is mounted.
Device is being initialized.
Drive 2 is not loaded.
Total Bytes Read=0 Blocks Read=0 Bytes/block=0
Positioned at File=0 Block=0
====
In Use Volume status:
000044L2 on device "LTO2C" (/dev/nst2)
000045L2 on device "LTO2B" (/dev/nst1)
====
All config files are available at http://sbgrid.org/bacula/
Sorry for the long post, and thanks for any help!
Ian
-------------------------------------------------------------------------
Using Tomcat but need to do more? Need to support web services, security?
Get stuff done quickly with pre-integrated technology to make your job easier
Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
