Bacula-users

Re: [Bacula-users] No bacula volume is mounted, but the volume is in use on the same device

2010-01-06 18:30:42
Subject: Re: [Bacula-users] No bacula volume is mounted, but the volume is in use on the same device
From: Javier Barroso <javibarroso AT gmail DOT com>
To: bacula-users AT lists.sourceforge DOT net
Date: Thu, 7 Jan 2010 00:27:45 +0100
Hi,
On Tue, Jan 5, 2010 at 12:36 PM, Javier Barroso <javibarroso AT gmail DOT com> 
wrote:
> On Tue, Jan 5, 2010 at 12:18 PM, John Drescher <drescherjm AT gmail DOT com> 
> wrote:
>> On Tue, Jan 5, 2010 at 4:26 AM, Javier Barroso <javibarroso AT gmail DOT 
>> com> wrote:
>>> Hi people,
>>>
>>> First, I'm using an old bacula version (etch version 1.38.11-8), so I
>>> now this is a 2006 question :(
> ...
>>> # mtx -f /dev/autochanger1 load 4 0
>>> * mount
>>> * status storage
>>> ...
>>> Device status:
>>> Autochanger "Autochanger" with devices:
>>>   "Drive-1" (/dev/st0)
>>> Device "FileStorage" (/tmp) is not open or does not exist.
>>> Device "Drive-1" (/dev/st0) open but no Bacula volume is mounted.
>>>    Device is BLOCKED waiting for media.
>>>    Slot 4 is loaded in drive 0.
>>>    Total Bytes Read=0 Blocks Read=0 Bytes/block=0
>>>    Positioned at File=0 Block=0
>>> Device "Drive-2" (/dev/st1) open but no Bacula volume is mounted.
>>>    Total Bytes Read=0 Blocks Read=0 Bytes/block=0
>>>    Positioned at File=0 Block=0
>>> ====
>>>
>>> In Use Volume status:
>>> ISOLAD01 on device "Drive-1" (/dev/st0)
>>> ====
>>> You have messages
>>> *
>>> 05-Jan 10:18 backup-sd: 3301 Issuing autochanger "loaded drive 0" command.
>>> 05-Jan 10:18 backup-sd: 3302 Autochanger "loaded drive 0", result is Slot 4.
>>> 05-Jan 10:18 backup-sd: 3301 Issuing autochanger "loaded drive 0" command.
>>> 05-Jan 10:18 backup-sd: 3302 Autochanger "loaded drive 0", result is Slot 4.
>>> 05-Jan 10:18 backup-sd: 3301 Issuing autochanger "loaded drive 0" command.
>>> 05-Jan 10:18 backup-sd: 3302 Autochanger "loaded drive 0", result is Slot 4.
>>> 05-Jan 10:18 backup-sd: Please mount Volume "ISOLAD01" on Storage
>>> Device "Drive-1" (/dev/st0) for Job openbravodb.2010-01-04_20.00.06
>>>
>>> # ISOLAD01 is a volume in bacula db
>>> * list media pool=DiarioLunes
>>> Pool: DiarioLunes
>>> +---------+------------+-----------+-----------------+----------+--------------+---------+------+-----------+---------------+---------------------+
>>> | MediaId | VolumeName | VolStatus | VolBytes        | VolFiles |
>>> VolRetention | Recycle | Slot | InChanger | MediaType     |
>>> LastWritten         |
>>> +---------+------------+-----------+-----------------+----------+--------------+---------+------+-----------+---------------+---------------------+
>>> |      51 | ISOLAD01   | Append    | 371,662,282,376 |      523 |
>>> 518,400 |       1 |    4 |         1 | Ultrium3-SCSI | 2009-10-20
>>> 02:33:52 |
>>>
>>> So, what am I missing ? Any help is appreciated.
>>
>> Nothing. There are bugs like this in 1.38.
>>
>> 1) Change /dev/st0 to /dev/nst0 in your config so bacula does not
>> accidentally delete one of your volumes.
>>
>> 2) Stop bacula-sd
>>
>> 3) Manually remove the tape using the autohanger command
>>
>> 4) Restart bacula-sd. Your jobs probably will have been terminated by
>> this action.
>>
> Thank you very much, I'll try it the next time it happens (I'll change
> my config like in your tip)
Ok, so I tried it again, and the same issue (bacula want a tape which
is mounted, but it doesn't recognize)

I tracked the problem i turned on debug in mtx-changer, and see about
mt -f /dev/nst0 status was telling "mt: /dev/nst0: No medium found"

Then I tried mt -f with the others three devices (I have an
autochanger with /dev/nst{0,1,2,3} as tapes) and see only nst2 was
online.

I changed my config to /dev/nst2, and bacula is now working again.

But I'm confused now ! :( :(. Somebody can explain me this situation ?:

# mtx -f /dev/autochanger1 status | head -6
  Storage Changer /dev/autochanger1:4 Drives, 60 Slots ( 2 Import/Export )
Data Transfer Element 0:Full (Storage Element 2 Loaded):VolumeTag =
ISOXAD02
Data Transfer Element 1:Empty
Data Transfer Element 2:Empty
Data Transfer Element 3:Empty

# lsscsi
[0:0:0:0]    mediumx HP       MSL6000 Series   0520  /dev/sch0
[0:0:0:1]    tape    HP       Ultrium 3-SCSI   G63W  /dev/st2
[0:0:0:2]    tape    HP       Ultrium 3-SCSI   G63W  /dev/st3
[0:0:0:3]    storage HP       NS E1200-320     593d  -
[1:0:3:0]    tape    HP       Ultrium 3-SCSI   G63W  /dev/st0
[1:0:4:0]    tape    HP       Ultrium 3-SCSI   G54W  /dev/st1

I can guess that first Data Transfer element listed in mtx -f dev
status is the first tape found in lsscsi command output. Then Data
Transfert Element 1 will be /dev/st3 and go ...

Is this true ? Should i name my devices with some persistente name
like "/dev/tape1" ?

And more important, why are others (three) devices like "not medium found" ?

See next session (first I loaded 4 tapes):
# mtx -f /dev/autochanger1 status | head -10
  Storage Changer /dev/autochanger1:4 Drives, 60 Slots ( 2 Import/Export )
Data Transfer Element 0:Full (Storage Element 2 Loaded):VolumeTag =
ISOXAD02
Data Transfer Element 1:Full (Storage Element 1 Loaded):VolumeTag =
ISOVBF04
Data Transfer Element 2:Full (Storage Element 3 Loaded):VolumeTag =
ISOVAF03
Data Transfer Element 3:Full (Storage Element 4 Loaded):VolumeTag =
ISOLAD01

# Bacula is using Data  Transfer Element 0:
* st st
...
Device "Drive-1" (/dev/nst2) is mounted with Volume="ISOXAD02"
Pool="DiarioMiercoles"
...

# But nst3 device is not ready, a while ago nst0 and nst1 wasn't ONLINE yet:
# mt -f /dev/nst0 status
drive type = Generic SCSI-2 tape
drive status = 1140850688
sense key error = 0
residue count = 0
file number = 0
block number = 0
Tape block size 0 bytes. Density code 0x44 (unknown).
Soft error count since last status=0
General status bits on (41010000):
 BOT ONLINE IM_REP_EN
backup:/var/log/bacula# mt -f /dev/nst1 status
drive type = Generic SCSI-2 tape
drive status = 1140850688
sense key error = 0
residue count = 0
file number = 0
block number = 0
Tape block size 0 bytes. Density code 0x44 (unknown).
Soft error count since last status=0
General status bits on (41010000):
 BOT ONLINE IM_REP_EN
backup:/var/log/bacula# mt -f /dev/nst2 status
mt: /dev/nst2: Device or resource busy
backup:/var/log/bacula# mt -f /dev/nst3 status
mt: /dev/nst3: Device or resource busy

My question now is, should be possible using /dev/nst3 while nst2 is
being used ? They are both connected through a NSR to the MSL library.

Sorry for this large post

Where do you recommend read about this kind of issues ?

Thanks !
PD: I'll upgrade to lenny / bacula 2.4, but this is like the problem
is not with bacula directly

------------------------------------------------------------------------------
This SF.Net email is sponsored by the Verizon Developer Community
Take advantage of Verizon's best-in-class app development support
A streamlined, 14 day to market process makes app distribution fast and easy
Join now and get one step closer to millions of Verizon customers
http://p.sf.net/sfu/verizon-dev2dev 
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users