Okay, here's more informational information. :)
I've attached the logs sections for both jobs.
For both jobs which required me to mount a tape I had something
like the following happen.
----------------------------------------
22-May 05:16 tibor-sd JobId 4223: 3301 Issuing autochanger "loaded? drive 0"
command.
22-May 05:16 tibor-sd JobId 4223: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
22-May 05:16 tibor-sd JobId 4223: 3304 Issuing autochanger "load slot 29, drive
0" command.
22-May 05:17 tibor-sd JobId 4223: 3305 Autochanger "load slot 29, drive 0",
status is OK.
22-May 05:17 tibor-sd JobId 4223: Volume "100116L2" previously written, moving
to end of data.
22-May 05:17 tibor-sd JobId 4223: Error: Unable to position to end of data on
device "NEO-LTO-0" (/dev/nst0): ERR=dev.c:946 ioctl MTIOCGET erro
r on "NEO-LTO-0" (/dev/nst0). ERR=Input/output error.
22-May 05:17 tibor-sd JobId 4223: Marking Volume "100116L2" in Error in Catalog.
22-May 05:17 tibor-sd JobId 4223: 3307 Issuing autochanger "unload slot 29,
drive 0" command.
22-May 05:17 tibor-sd JobId 4223: 3995 Bad autochanger "unload slot 29, drive
0": ERR=Child exited with code 1
Results=Unloading drive 0 into Storage Element 29...mtx: Request Sense: Long
Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 53
mtx: Request Sense: Additional Sense Qualifier = 02
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 480 to 60 Failed
----------------------------------------
So, it came across a "bad" tape, puked, tried to unload to slot and
failed. It tried the unload twice (within the same minute) failed
both times, then sat there waiting for me to issue the mount command,
which succeeded.
Could it be a timing issue?
-John
On Fri, May 22, 2009 at 11:58:44AM -0400, John Lockard wrote:
> And if I mounted a tape immediately after and also made sure
> that automout was set to yes? Whenever I unmount a tape I
> always make sure to mount another in it's stead.
>
> I'll dig through previous and current job and daemon messages
> when I get back to my normal office.
>
> -John
>
> On Fri, May 22, 2009 at 11:03:51AM -0400, John Drescher wrote:
> > On Fri, May 22, 2009 at 10:45 AM, John Lockard <jlock...@umich.edu> wrote:
> > > Hi All,
> > >
> > > I know I don't have full information here, but don't want to send along
> > > my full config as I'll guess that's overkill.
> > >
> > > 22-May 06:17 tibor-sd JobId 4223: Please mount Volume "100027L2" or label
> > > a new one for:
> > > Job: Belobog-Data2-Users.2009-05-22_05.15.00_35
> > > Storage: "NEO-LTO-0" (/dev/nst0)
> > > Pool: Radev-Diff
> > > Media type: LTO-2
> > > 22-May 06:19 tibor-sd JobId 4209: Please mount Volume "000152L2" or label
> > > a new one for:
> > > Job: BackupCatalog.2009-05-21_23.10.00_21
> > > Storage: "NEO-LTO-1" (/dev/nst1)
> > > Pool: Weekly-Tape-WH
> > > Media type: LTO-2
> > >
> > > I have a Overland Neo 4000 Tape Library with 57 slots and 3 tape drives.
> > > My config is set to Automount tapes when needed. But, sometimes it
> > > doesn't
> > > and just sits there, waiting for me to manually load the requested tapes.
> > > I had two instances of that this morning. Both tapes were in the Library
> > > and checking which tapes Bacula thought were loaded showed both of these
> > > tapes as being "In Changer". I was able to easily do:
> > > mount storage=Overland_Neo_4000 drive=0 slot=30
> > > mount storage=Overland_Neo_4000 drive=1 slot=1
> > >
> > > Then my jobs continued running nicely.
> > >
> > > What would be the reasons that occasionally Bacula won't automount tapes
> > > which it knows are present?
> > >
> >
> > One reason is if you umounted the previous tape.
> >
> > John
> >
> >
>
> --
> "A photograph is usually looked at - seldom looked into." - Ansel Adams
> -------------------------------------------------------------------
> John M. Lockard | U of Michigan - School of Information
> Unix and Security Admin | 1214 SI North - 1075 Beal Ave.
> jlock...@umich.edu | Ann Arbor, MI 48109-2112
> www.umich.edu/~jlockard | 734-615-8776 | 734-647-8045 FAX
> -------------------------------------------------------------------
>
> ------------------------------------------------------------------------------
> Register Now for Creativity and Technology (CaT), June 3rd, NYC. CaT
> is a gathering of tech-side developers & brand creativity professionals. Meet
> the minds behind Google Creative Lab, Visual Complexity, Processing, &
> iPhoneDevCamp asthey present alongside digital heavyweights like Barbarian
> Group, R/GA, & Big Spaceship. http://www.creativitycat.com
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
>
>
--
You're not how much money you have in the bank.
-------------------------------------------------------------------
John M. Lockard | U of Michigan - School of Information
Unix and Security Admin | 1214 SI North - 1075 Beal Ave.
jlock...@umich.edu | Ann Arbor, MI 48109-2112
www.umich.edu/~jlockard | 734-615-8776 | 734-647-8045 FAX
-------------------------------------------------------------------
22-May 05:15 tibor-dir JobId 4223: Start Backup JobId 4223,
Job=Belobog-Data2-Users.2009-05-22_05.15.00_35
22-May 05:15 tibor-sd JobId 4223: 3307 Issuing autochanger "unload slot 42,
drive 0" command.
22-May 05:16 tibor-dir JobId 4223: Using Device "NEO-LTO-0"
22-May 05:16 tibor-sd JobId 4223: 3301 Issuing autochanger "loaded? drive 0"
command.
22-May 05:16 tibor-sd JobId 4223: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
22-May 05:16 tibor-sd JobId 4223: 3304 Issuing autochanger "load slot 29, drive
0" command.
22-May 05:17 tibor-sd JobId 4223: 3305 Autochanger "load slot 29, drive 0",
status is OK.
22-May 05:17 tibor-sd JobId 4223: Volume "100116L2" previously written, moving
to end of data.
22-May 05:17 tibor-sd JobId 4223: Error: Unable to position to end of data on
device "NEO-LTO-0" (/dev/nst0): ERR=dev.c:946 ioctl MTIOCGET error on
"NEO-LTO-0" (/dev/nst0). ERR=Input/output error.
22-May 05:17 tibor-sd JobId 4223: Marking Volume "100116L2" in Error in Catalog.
22-May 05:17 tibor-sd JobId 4223: 3307 Issuing autochanger "unload slot 29,
drive 0" command.
22-May 05:17 tibor-sd JobId 4223: 3995 Bad autochanger "unload slot 29, drive
0": ERR=Child exited with code 1
Results=Unloading drive 0 into Storage Element 29...mtx: Request Sense: Long
Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 53
mtx: Request Sense: Additional Sense Qualifier = 02
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 480 to 60 Failed
22-May 05:17 tibor-dir JobId 4223: Recycled volume "100027L2"
22-May 05:17 tibor-dir JobId 4223: Using Volume "100027L2" from 'Scratch' pool.
22-May 05:17 tibor-sd JobId 4223: 3301 Issuing autochanger "loaded? drive 0"
command.
22-May 05:17 tibor-sd JobId 4223: 3302 Autochanger "loaded? drive 0", result is
Slot 29.
22-May 05:17 tibor-sd JobId 4223: 3307 Issuing autochanger "unload slot 29,
drive 0" command.
22-May 05:17 tibor-sd JobId 4223: 3995 Bad autochanger "unload slot 29, drive
0": ERR=Child exited with code 1
Results=Unloading drive 0 into Storage Element 29...mtx: Request Sense: Long
Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 53
mtx: Request Sense: Additional Sense Qualifier = 02
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 480 to 60 Failed
22-May 05:17 tibor-sd JobId 4223: Please mount Volume "100027L2" or label a new
one for:
Job: Belobog-Data2-Users.2009-05-22_05.15.00_35
Storage: "NEO-LTO-0" (/dev/nst0)
Pool: Radev-Diff
Media type: LTO-2
22-May 06:17 tibor-sd JobId 4223: Please mount Volume "100027L2" or label a new
one for:
Job: Belobog-Data2-Users.2009-05-22_05.15.00_35
Storage: "NEO-LTO-0" (/dev/nst0)
Pool: Radev-Diff
Media type: LTO-2
22-May 08:17 tibor-sd JobId 4223: Please mount Volume "100027L2" or label a new
one for:
Job: Belobog-Data2-Users.2009-05-22_05.15.00_35
Storage: "NEO-LTO-0" (/dev/nst0)
Pool: Radev-Diff
Media type: LTO-2
22-May 10:24 tibor-sd JobId 4223: 3301 Issuing autochanger "loaded? drive 0"
command.
22-May 10:24 tibor-sd JobId 4223: 3302 Autochanger "loaded? drive 0", result is
Slot 29.
22-May 10:24 tibor-sd JobId 4223: 3307 Issuing autochanger "unload slot 29,
drive 0" command.
22-May 10:24 tibor-sd JobId 4223: 3301 Issuing autochanger "loaded? drive 0"
command.
22-May 10:24 tibor-sd JobId 4223: 3302 Autochanger "loaded? drive 0", result:
nothing loaded.
22-May 10:24 tibor-sd JobId 4223: 3304 Issuing autochanger "load slot 30, drive
0" command.
22-May 10:25 tibor-sd JobId 4223: 3305 Autochanger "load slot 30, drive 0",
status is OK.
22-May 10:25 tibor-sd JobId 4223: Recycled volume "100027L2" on device
"NEO-LTO-0" (/dev/nst0), all previous data lost.
22-May 10:25 tibor-sd JobId 4223: Spooling data ...
21-May 23:10 tibor-dir JobId 4209: shell command: run BeforeJob
"/etc/bacula/make_catalog_backup bacula bacula"
21-May 23:18 tibor-dir JobId 4209: Start Backup JobId 4209,
Job=BackupCatalog.2009-05-21_23.10.00_21
21-May 23:18 tibor-dir JobId 4209: Using Device "NEO-LTO-1"
21-May 23:18 tibor-sd JobId 4209: Volume "100092L2" previously written, moving
to end of data.
21-May 23:19 tibor-sd JobId 4209: Error: Unable to position to end of data on
device "NEO-LTO-1" (/dev/nst1): ERR=dev.c:946 ioctl MTIOCGET error on
"NEO-LTO-1" (/dev/nst1). ERR=Input/output error.
21-May 23:19 tibor-sd JobId 4209: Marking Volume "100092L2" in Error in Catalog.
21-May 23:19 tibor-sd JobId 4209: 3307 Issuing autochanger "unload slot 3,
drive 1" command.
21-May 23:19 tibor-sd JobId 4209: 3995 Bad autochanger "unload slot 3, drive
1": ERR=Child exited with code 1
Results=Unloading drive 1 into Storage Element 3...mtx: Request Sense: Long
Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 53
mtx: Request Sense: Additional Sense Qualifier = 02
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 481 to 34 Failed
21-May 23:19 tibor-sd JobId 4209: 3301 Issuing autochanger "loaded? drive 1"
command.
21-May 23:19 tibor-sd JobId 4209: 3302 Autochanger "loaded? drive 1", result is
Slot 3.
21-May 23:19 tibor-sd JobId 4209: 3307 Issuing autochanger "unload slot 3,
drive 1" command.
21-May 23:19 tibor-sd JobId 4209: 3995 Bad autochanger "unload slot 3, drive
1": ERR=Child exited with code 1
Results=Unloading drive 1 into Storage Element 3...mtx: Request Sense: Long
Report=yes
mtx: Request Sense: Valid Residual=no
mtx: Request Sense: Error Code=70 (Current)
mtx: Request Sense: Sense Key=Illegal Request
mtx: Request Sense: FileMark=no
mtx: Request Sense: EOM=no
mtx: Request Sense: ILI=no
mtx: Request Sense: Additional Sense Code = 53
mtx: Request Sense: Additional Sense Qualifier = 02
mtx: Request Sense: BPV=no
mtx: Request Sense: Error in CDB=no
mtx: Request Sense: SKSV=no
MOVE MEDIUM from Element Address 481 to 34 Failed
21-May 23:19 tibor-sd JobId 4209: Please mount Volume "000152L2" or label a new
one for:
Job: BackupCatalog.2009-05-21_23.10.00_21
Storage: "NEO-LTO-1" (/dev/nst1)
Pool: Weekly-Tape-WH
Media type: LTO-2
22-May 00:19 tibor-sd JobId 4209: Please mount Volume "000152L2" or label a new
one for:
Job: BackupCatalog.2009-05-21_23.10.00_21
Storage: "NEO-LTO-1" (/dev/nst1)
Pool: Weekly-Tape-WH
Media type: LTO-2
22-May 02:19 tibor-sd JobId 4209: Please mount Volume "000152L2" or label a new
one for:
Job: BackupCatalog.2009-05-21_23.10.00_21
Storage: "NEO-LTO-1" (/dev/nst1)
Pool: Weekly-Tape-WH
Media type: LTO-2
22-May 06:19 tibor-sd JobId 4209: Please mount Volume "000152L2" or label a new
one for:
Job: BackupCatalog.2009-05-21_23.10.00_21
Storage: "NEO-LTO-1" (/dev/nst1)
Pool: Weekly-Tape-WH
Media type: LTO-2
22-May 10:25 tibor-sd JobId 4209: 3301 Issuing autochanger "loaded? drive 1"
command.
22-May 10:25 tibor-sd JobId 4209: 3302 Autochanger "loaded? drive 1", result is
Slot 3.
22-May 10:26 tibor-sd JobId 4209: 3307 Issuing autochanger "unload slot 3,
drive 1" command.
22-May 10:27 tibor-sd JobId 4209: 3301 Issuing autochanger "loaded? drive 1"
command.
22-May 10:27 tibor-sd JobId 4209: 3302 Autochanger "loaded? drive 1", result:
nothing loaded.
22-May 10:27 tibor-sd JobId 4209: 3304 Issuing autochanger "load slot 1, drive
1" command.
22-May 10:27 tibor-sd JobId 4209: 3305 Autochanger "load slot 1, drive 1",
status is OK.
22-May 10:27 tibor-sd JobId 4209: Volume "000152L2" previously written, moving
to end of data.
22-May 10:28 tibor-sd JobId 4209: Ready to append to end of Volume "000152L2"
at file=61.
22-May 10:28 tibor-sd JobId 4209: Spooling data ...
22-May 10:31 tibor-sd JobId 4209: Job write elapsed time = 00:02:34, Transfer
rate = 76.40 M bytes/second
22-May 10:31 tibor-sd JobId 4209: Committing spooled data to Volume "000152L2".
Despooling 11,777,035,227 bytes ...
22-May 10:35 tibor-sd JobId 4209: Despooling elapsed time = 00:03:48, Transfer
rate = 51.65 M bytes/second
------------------------------------------------------------------------------
Register Now for Creativity and Technology (CaT), June 3rd, NYC. CaT
is a gathering of tech-side developers & brand creativity professionals. Meet
the minds behind Google Creative Lab, Visual Complexity, Processing, &
iPhoneDevCamp asthey present alongside digital heavyweights like Barbarian
Group, R/GA, & Big Spaceship. http://www.creativitycat.com
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
