Hello,

On 12/17/2005 11:13 PM, Kern Sibbald wrote:
Hello Arno,

Now we are very close to finding the problem.

Damn good news. Something this day (or yesterday, rather) really needs :-|

Can you send me the beginning of the log output that shows
reserve.c:493 ... ?

No. See below.

 It should have 3 or four of those lines reserve.c:493
before it goes into the endless loop. That is the part that will tell me what combination of drives and switches is not finding a drive in your case. What is important is that I can see all the output beginning with the first reserve.c:493, continuing up to the point that it starts repeating over and over reserve.c:552 .... reserve.c:571,


Ok, following is the start of todays evening session with Bacula. I simply have no lines from reserve.c line 493... see for yourself.

495 is what comes closest, and I have marked the end of the initialization process with ****

goblin:/etc/bacula # more /var/bacula/server/bacula-sd.log.16-Dec-22\:03
bacula-sd: stored_conf.c:613 Inserting director res: elf-monitor
bacula-sd: stored_conf.c:613 Inserting device res: Wangtek 6525
bacula-sd: stored_conf.c:613 Inserting device res: HP DAT 0
bacula-sd: stored_conf.c:613 Inserting autochanger res: FastStor 4000
bacula-sd: stored_conf.c:613 Inserting device res: Quantum DLT 0
bacula-sd: stored_conf.c:613 Inserting director res: elf-monitor
bacula-sd: stored_conf.c:613 Inserting device res: Wangtek 6525
bacula-sd: stored_conf.c:613 Inserting device res: HP DAT 0
bacula-sd: stored_conf.c:613 Inserting autochanger res: FastStor 4000
bacula-sd: stored_conf.c:613 Inserting device res: Quantum DLT 0
goblin-sd: jcr.c:113 read_last_jobs seek to 188
goblin-sd: jcr.c:120 Read num_items=10
goblin-sd: pythonlib.c:94 No script dir. prog=SDStartUp
goblin-sd: stored.c:451 calling init_dev /var/bacula/
goblin-sd: dev.c:242 init_dev: tape=0 dev_name=/var/bacula/
goblin-sd: stored.c:453 SD init done /var/bacula/
goblin-sd: stored.c:451 calling init_dev /dev/nst0
goblin-sd: dev.c:242 init_dev: tape=2 dev_name=/dev/nst0
goblin-sd: stored.c:453 SD init done /dev/nst0
goblin-sd: stored.c:466 calling first_open_device "Wangtek 6525" (/dev/nst0)
goblin-sd: bnet_server.c:83 Addresses host[ipv4:0.0.0.0:9103]
goblin-sd: dev.c:277 open dev: tape=2 dev_name="Wangtek 6525" (/dev/nst0) vol= mode=OPEN_READ_ONLY
goblin-sd: dev.c:334 open dev: device is tape
goblin-sd: dev.c:349 Try open "Wangtek 6525" (/dev/nst0) mode=OPEN_READ_ONLY nonblocking=2048
goblin-sd: dev.c:380 openmode=3 OPEN_READ_ONLY
goblin-sd: dev.c:393 open dev: tape 6 opened
goblin-sd: label.c:71 Enter read_volume_label res=0 device="Wangtek 6525" (/dev/nst0) vol= dev_Vol=*NULL*
goblin-sd: dev.c:645 rewind_dev res=0 fd=6 "Wangtek 6525" (/dev/nst0)
goblin-sd: label.c:138 Big if statement in read_volume_label
goblin-sd: label.c:206 Compare Vol names: VolName= hdr=QIC-525-0046
goblin-sd: label.c:222 Copy vol_name=QIC-525-0046

Volume Label:
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : QIC-525-0046
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 162
PoolName          : QIC
MediaType         : DC6525
PoolType          : Backup
HostName          : goblin
Date label written: 25-Feb-2005 20:21
goblin-sd: label.c:227 Leave read_volume_label() VOL_OK
goblin-sd: dev.c:645 rewind_dev res=0 fd=6 "Wangtek 6525" (/dev/nst0)
goblin-sd: stored.c:451 calling init_dev /dev/nst1
goblin-sd: dev.c:242 init_dev: tape=2 dev_name=/dev/nst1
goblin-sd: stored.c:453 SD init done /dev/nst1
goblin-sd: autochanger.c:247 Locking changer HP DAT
goblin-sd: autochanger.c:218 run_prog: /etc/bacula/mtx-changer /dev/sg4 loaded 0 /dev/nst1 0 stat=0 result=0

goblin-sd: autochanger.c:256 Unlocking changer HP DAT
goblin-sd: stored.c:466 calling first_open_device "HP DAT 0" (/dev/nst1)
goblin-sd: dev.c:277 open dev: tape=2 dev_name="HP DAT 0" (/dev/nst1) vol= mode=OPEN_READ_ONLY
goblin-sd: dev.c:334 open dev: device is tape
goblin-sd: autochanger.c:247 Locking changer HP DAT
goblin-sd: autochanger.c:218 run_prog: /etc/bacula/mtx-changer /dev/sg4 loaded 0 /dev/nst1 0 stat=0 result=0

goblin-sd: autochanger.c:256 Unlocking changer HP DAT
goblin-sd: dev.c:349 Try open "HP DAT 0" (/dev/nst1) mode=OPEN_READ_ONLY nonblocking=2048
goblin-sd: dev.c:380 openmode=3 OPEN_READ_ONLY
goblin-sd: dev.c:393 open dev: tape 7 opened
goblin-sd: label.c:71 Enter read_volume_label res=0 device="HP DAT 0" (/dev/nst1) vol= dev_Vol=*NULL*
goblin-sd: dev.c:645 rewind_dev res=0 fd=7 "HP DAT 0" (/dev/nst1)
goblin-sd: label.c:104 return VOL_NO_MEDIA: Couldn't rewind device "HP DAT 0" (/dev/nst1): ERR=dev.c:679 Rewind e
rror on "HP DAT 0" (/dev/nst1). ERR=No medium found.

goblin-sd: stored.c:451 calling init_dev /dev/nst2
goblin-sd: dev.c:242 init_dev: tape=2 dev_name=/dev/nst2
goblin-sd: stored.c:453 SD init done /dev/nst2
goblin-sd: autochanger.c:247 Locking changer FastStor 4000
goblin-sd: autochanger.c:218 run_prog: /etc/bacula/mtx-changer /dev/sg7 loaded 0 /dev/nst2 0 stat=0 result=0

goblin-sd: autochanger.c:256 Unlocking changer FastStor 4000
goblin-sd: stored.c:466 calling first_open_device "Quantum DLT 0" (/dev/nst2) goblin-sd: dev.c:277 open dev: tape=2 dev_name="Quantum DLT 0" (/dev/nst2) vol= mode=OPEN_READ_ONLY
goblin-sd: dev.c:334 open dev: device is tape
goblin-sd: autochanger.c:247 Locking changer FastStor 4000
goblin-sd: autochanger.c:218 run_prog: /etc/bacula/mtx-changer /dev/sg7 loaded 0 /dev/nst2 0 stat=0 result=0

goblin-sd: autochanger.c:256 Unlocking changer FastStor 4000
goblin-sd: dev.c:349 Try open "Quantum DLT 0" (/dev/nst2) mode=OPEN_READ_ONLY nonblocking=2048
goblin-sd: dev.c:380 openmode=3 OPEN_READ_ONLY
goblin-sd: dev.c:393 open dev: tape 8 opened
goblin-sd: label.c:71 Enter read_volume_label res=0 device="Quantum DLT 0" (/dev/nst2) vol= dev_Vol=*NULL*
goblin-sd: dev.c:645 rewind_dev res=0 fd=8 "Quantum DLT 0" (/dev/nst2)
goblin-sd: label.c:104 return VOL_NO_MEDIA: Couldn't rewind device "Quantum DLT 0" (/dev/nst2): ERR=dev.c:679 Rew
ind error on "Quantum DLT 0" (/dev/nst2). ERR=No medium found.

goblin-sd: bnet.c:1128 who=client host=192.168.0.3 port=36643
goblin-sd: cram-md5.c:52 send: auth cram-md5 <[EMAIL PROTECTED]> ssl=0
goblin-sd: cram-md5.c:68 Authenticate OK OjxsH7+UY5VFkH+K55d+BB
goblin-sd: cram-md5.c:97 cram-get: auth cram-md5 <[EMAIL PROTECTED]> ssl=0
goblin-sd: cram-md5.c:114 sending resp to challenge: e6+36i//qU9O+m4tC9+C3A
goblin-sd: dircmd.c:187 Message channel init completed.

**** here, one backup job is started.

goblin-sd: job.c:70 <dird: JobId=4500 job=Goblin.2005-12-16_22.04.31 job_name=Goblin client_name=goblin-fd type=6 6 level=73 FileSet=LinuxGoblin NoAttr=0 SpoolAttr=0 FileSetMD5=l4Uaa3+CV7xORjcBJ6hIPC SpoolData=1 WritePartAfterJ
ob=0 PreferMountedVols=1
goblin-sd: job.c:123 >dird: 3000 OK Job SDid=1 SDtime=1134767018 Authorization=IBFB-DHAA-AGPN-HGIC-MNAM-ODAH-HCJH
-EPEC
goblin-sd: pythonlib.c:216 No startup module.
goblin-sd: reserve.c:308 <dird: use storage=HPDAT media_type=DDS2 pool_name=Incr pool_type=Backup append=1 copy=0
 stripe=0
goblin-sd: reserve.c:331 <dird device: use device=HPDAT
goblin-sd: reserve.c:495 PrefMnt=1 exact=1 no_wait=1 availchgr=0
goblin-sd: reserve.c:552 Search res for HP DAT
goblin-sd: reserve.c:555 Try res=GoblinFile
goblin-sd: reserve.c:555 Try res=Wangtek 6525
goblin-sd: reserve.c:555 Try res=HP DAT 0
goblin-sd: reserve.c:555 Try res=Quantum DLT 0
goblin-sd: reserve.c:571 Try changer res=HP DAT
goblin-sd: reserve.c:576 Try changer device HP DAT 0
goblin-sd: reserve.c:634 Try reserve HP DAT 0 jobid=4500
goblin-sd: askdir.c:242 >dird: CatReq Job=Goblin.2005-12-16_22.04.31 FindMedia=1 pool_name=Incr media_type=DDS2 goblin-sd: askdir.c:165 <dird 1000 OK VolName=DAT-120-0009 VolJobs=1 VolFiles=1 VolBlocks=11757 VolBytes=75846531 8 VolMounts=41 VolErrors=0 VolWrites=1174380 MaxVolBytes=0 VolCapacityBytes=0 VolStatus=Append Slot=3 MaxVolJobs= 0 MaxVolFiles=0 InChanger=1 VolReadTime=0 VolWriteTime=0 EndFile=0 EndBlock=0 VolParts=0 LabelType=0
goblin-sd: reserve.c:650 Looking for Volume=DAT-120-0009
goblin-sd: reserve.c:760 reserve_append device is tape
goblin-sd: reserve.c:794 can_reserve_drive: prefmnt=1 busy=0 res=0
goblin-sd: reserve.c:798 failed: want mounted -- no vol JobId=4500
goblin-sd: reserve.c:763 can_reserve_drive!=1
goblin-sd: reserve.c:676 Not OK.
goblin-sd: reserve.c:571 Try changer res=FastStor 4000
goblin-sd: reserve.c:495 PrefMnt=1 exact=0 no_wait=1 availchgr=0
goblin-sd: reserve.c:552 Search res for HP DAT
goblin-sd: reserve.c:555 Try res=GoblinFile
goblin-sd: reserve.c:555 Try res=Wangtek 6525
goblin-sd: reserve.c:555 Try res=HP DAT 0
goblin-sd: reserve.c:555 Try res=Quantum DLT 0

Arno

On Saturday 17 December 2005 21:54, Arno Lehmann wrote:

Hello,

On 12/17/2005 8:38 PM, Natxo Asenjo wrote:

hi,

Following the instructions in
http://bacula.org/rel-manual/Backup_Strategies.html#SECTION00028330000000
0000000

I have a little problem. The script /etc/bacula/end_of_backup.sh when
run manually works fine, when run at the end of the job I get this
message:

17-Dec 20:26 tux-dir: RunAfter: + echo root
17-Dec 20:26 tux-dir: RunAfter: root
17-Dec 20:26 tux-dir: RunAfter: + /etc/bacula/delete_catalog_backup
17-Dec 20:26 tux-dir: RunAfter: + mt rewind
17-Dec 20:26 tux-dir: RunAfter: mt: /dev/tape: Permission denied
17-Dec 20:26 tux-dir: RunAfter: + mt eject
17-Dec 20:26 tux-dir: RunAfter: mt: /dev/tape: Permission denied
17-Dec 20:26 tux-dir: RunAfter: + exit 0

Hmm. Are you using a debian linux system? I think I remember something...


So obviously the tape is not ejected and I need to eject it manually.

Obviously.
You might try inserting something like
echo 'umount TAPE' | bconsole
in your script before the mt eject. And perhaps mt rewoffl is also worth
a try.


ls -l /etc/bacula/end_of_backup.sh
-rwsr-sr--  1 root bacula 97 Dec 17 20:16 /etc/bacula/end_of_backup.sh

I have even (OMG)


:-)
:

tried setting the suid bit on the script to no avail.

Shouldn't work, as far as I know...


In fact, I have a echo statement at the beginnig of the script that
confirms that it runs as root (echo $USER), so I am not sure what the
problem is. This is bacula 1.38.2 and for the rest it's great!
I sure would like to have this daily tape rotation because at our
company we already have this rotation and one of the workers is used to
this, so i'd rather not change it.

Good reason, I think.

Arno



--
IT-Service Lehmann                    [EMAIL PROTECTED]
Arno Lehmann                  http://www.its-lehmann.de


-------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc. Do you grep through log files
for problems?  Stop!  Download the new AJAX search engine that makes
searching your log files as easy as surfing the  web.  DOWNLOAD SPLUNK!
http://ads.osdn.com/?ad_id=7637&alloc_id=16865&op=click
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users

Reply via email to