Daemon logs -d 200: storage unload, 9.0.3 with standalone tape drive

classic Classic list List threaded Threaded
3 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Daemon logs -d 200: storage unload, 9.0.3 with standalone tape drive

Phil Stracchino-2
Sorry for the length.  This is a complete log history from starting the
SD (with a tape already loaded) and the director, starting a BAT, doing
a STATUS STORAGE, then an UMOUNT STORAGE=babylon5-sd, all at -d 200.


Summary:

When the STATUS STORAGE is issued, the Director talks to the SD, the SD
replies, the Director posts the results.  All perfectly normal.

When the UMOUNT STORAGE is issued, the director sends the unmount command:

minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_cmds.c:1731-0 unmount: umount storage=babylon5-sd
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source

The SD receives *nothing*, does *nothing*, and logs *nothing*.  It
appears the SD does not receive either mount or umount commands.
Status, however, works, as do reads and writes.  I haven't tested LABEL.



Let me know if there's any further test data I can provide on this.  If
not, I need to roll back to 7.4.7.



LOGS:

SD start, with a tape already loaded in the drive:

babylon5:root:~:64 # /usr/sbin/bacula-sd -u root -g bacula -c
/etc/bacula/bacula-sd.conf -d 200 -f
bacula-sd: address_conf.c:274-0 Initaddr 0.0.0.0:9103
babylon5-sd: jcr.c:131-0 read_last_jobs seek to 192
babylon5-sd: jcr.c:138-0 Read num_items=10
babylon5-sd: stored.c:609-0 calling init_dev LTO-4
babylon5-sd: init_dev.c:116-0 init_dev dev_type=0
babylon5-sd: init_dev.c:152-0 Num drivers=15
babylon5-sd: init_dev.c:165-0 loadable=0 type=2 loaded=1 name=tape handle=0
babylon5-sd: init_dev.c:391-0 init_dev: tape=1 dev_name=/dev/nst0
babylon5-sd: stored.c:611-0 SD init done LTO-4
babylon5-sd: bnet_server.c:86-0 Addresses 0.0.0.0:9103
babylon5-sd: block_util.c:170-0 New block adata=0 len=2048000
block=7fea00002550
babylon5-sd: acquire.c:658-0 Attach 0x1f38 to dev "LTO-4" (/dev/nst0)
babylon5-sd: stored.c:642-0 calling first_open_device "LTO-4" (/dev/nst0)
babylon5-sd: device.c:300-0 start open_output_device()
babylon5-sd: device.c:313-0 Opening device.
babylon5-sd: dev.c:113-0 Enter: virtual bool DEVICE::open_device(DCR*, int)
babylon5-sd: tape_dev.c:981-0 Enter tape mount
babylon5-sd: tape_dev.c:89-0 Open dev: device is tape
babylon5-sd: tape_dev.c:104-0 Try open "LTO-4" (/dev/nst0)
mode=OPEN_READ_ONLY
babylon5-sd: tape_dev.c:127-0 Rewind after open
babylon5-sd: os.c:58-0 In set_os_device_parameters
babylon5-sd: os.c:80-0 MTSETDRVBUFFER
babylon5-sd: tape_dev.c:182-0 open dev: tape 5 opened
babylon5-sd: device.c:319-0 open dev "LTO-4" (/dev/nst0) OK
babylon5-sd: label.c:72-0 Enter: virtual int
DEVICE::read_dev_volume_label(DCR*)
babylon5-sd: label.c:75-0 Enter read_volume_label adata=0 res=0
device="LTO-4" (/dev/nst0) vol= dev_Vol=*NULL*
babylon5-sd: label.c:126-0 Big if statement in read_volume_label
babylon5-sd: block.c:513-0 Pos for read=0:0 0
babylon5-sd: block.c:527-0 Read() adata=0 vol= nbytes=1024 pos=0
babylon5-sd: block_util.c:456-0 set block=7fea00002550 adata=0 binbuf=205
babylon5-sd: block.c:620-0 adata=0 block_len=229 buf_len=2048000
babylon5-sd: block.c:727-0 Exit read_block read_len=1024 block_len=229
binbuf=205
babylon5-sd: record_read.c:211-0 Rdata full adata=0 FI=VOL_LABEL
SessId=1 Strm=0 len=193 block=7fea00002550
babylon5-sd: label.c:968-0 Enter: bool unser_volume_label(DEVICE*,
DEV_RECORD*)
babylon5-sd: label.c:985-0 reclen=193 recdata=Bacula 1.0 immortal
babylon5-sd: label.c:987-0 reclen=193 recdata=Bacula 1.0 immortal
babylon5-sd: label.c:1021-0 unser_vol_label

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : LTO4-FULL-0007
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 193
PoolName          : Full-Tape
MediaType         : LTO-4
PoolType          : Backup
HostName          : babylon5
Date label written: 01-Feb-2016 15:13
babylon5-sd: label.c:1025-0 Leave: bool unser_volume_label(DEVICE*,
DEV_RECORD*)
babylon5-sd: label.c:149-0 VolHdr.Id OK: Bacula 1.0 immortal

babylon5-sd: label.c:188-0 VolHdr.VerNum=11 OK.
babylon5-sd: label.c:208-0 Compare Vol names: VolName= hdr=LTO4-FULL-0007

Volume Label:
Adata             : 0
Id                : Bacula 1.0 immortal
VerNo             : 11
VolName           : LTO4-FULL-0007
PrevVolName       :
VolFile           : 0
LabelType         : VOL_LABEL
LabelSize         : 193
PoolName          : Full-Tape
MediaType         : LTO-4
PoolType          : Backup
HostName          : babylon5
Date label written: 01-Feb-2016 15:13
babylon5-sd: label.c:258-0 Leave read_volume_label() VOL_OK
babylon5-sd: label.c:271-0 Call reserve_volume=LTO4-FULL-0007
babylon5-sd: vol_mgr.c:381-0 enter reserve_volume=LTO4-FULL-0007
drive="LTO-4" (/dev/nst0)
babylon5-sd: vol_mgr.c:286-0 new Vol=LTO4-FULL-0007 slot=0 at
7fea000027c8 dev="LTO-4" (/dev/nst0)
babylon5-sd: vol_mgr.c:548-0 set in_use. vol=LTO4-FULL-0007 dev="LTO-4"
(/dev/nst0)
babylon5-sd: vol_mgr.c:582-0 Inc walk_start use_count=2
volname=LTO4-FULL-0007
babylon5-sd: vol_mgr.c:220-0 List end new volume: LTO4-FULL-0007
in_use=1 swap=0 slot=0 on Tape device "LTO-4" (/dev/nst0)
babylon5-sd: label.c:284-0 Leave: virtual int
DEVICE::read_dev_volume_label(DCR*)
babylon5-sd: vol_mgr.c:694-0 Clear in_use vol=LTO4-FULL-0007 slot=0
babylon5-sd: vol_mgr.c:711-0 set not reserved vol=LTO4-FULL-0007 slot=0
writers=0 reserves=0 dev="LTO-4" (/dev/nst0)



Director start:

minbar:root:~:28 # /usr/sbin/bacula-dir -u root -g bacula -c
/etc/bacula/bacula-dir.conf -d 200 -f
bacula-dir: dird.c:223-0 Debug level = 200
bacula-dir: address_conf.c:274-0 Initaddr 0.0.0.0:9101
bacula-dir: dird_conf.c:2035-0 Got name=no
bacula-dir: dird_conf.c:2047-0 Item=Autochanger got value=no
bacula-dir: inc_conf.c:530-0 set wildfile aca8b8 size=1 [A-Z]:/pagefile.sys
bacula-dir: inc_conf.c:530-0 set wildfile aca8b8 size=2 [A-Z]:/hiberfil.sys
bacula-dir: inc_conf.c:530-0 set wilddir aca8b8 size=1 [A-Z]:/RECYCLER
bacula-dir: inc_conf.c:530-0 set wilddir aca8b8 size=2 [A-Z]:/$RECYCLE.BIN
bacula-dir: inc_conf.c:530-0 set wilddir aca8b8 size=3 [A-Z]:/System
Volume Information
bacula-dir: dird_conf.c:2035-0 Got name=no
bacula-dir: dird_conf.c:2047-0 Item=Autochanger got value=no
bacula-dir: runscript.c:287-0 runscript: debug
bacula-dir: runscript.c:288-0  --> RunScript
bacula-dir: runscript.c:289-0   --> Command=/etc/bacula/checkhost %c
bacula-dir: runscript.c:290-0   --> Target=
bacula-dir: runscript.c:291-0   --> RunOnSuccess=1
bacula-dir: runscript.c:292-0   --> RunOnFailure=0
bacula-dir: runscript.c:293-0   --> FailJobOnError=1
bacula-dir: runscript.c:294-0   --> RunWhen=2
bacula-dir: runscript.c:287-0 runscript: debug
bacula-dir: runscript.c:288-0  --> RunScript
bacula-dir: runscript.c:289-0   --> Command=/etc/bacula/clean_volumes -v
bacula-dir: runscript.c:290-0   --> Target=
bacula-dir: runscript.c:291-0   --> RunOnSuccess=1
bacula-dir: runscript.c:292-0   --> RunOnFailure=0
bacula-dir: runscript.c:293-0   --> FailJobOnError=1
bacula-dir: runscript.c:294-0   --> RunWhen=2
bacula-dir: runscript.c:287-0 runscript: debug
bacula-dir: runscript.c:288-0  --> RunScript
bacula-dir: runscript.c:289-0   --> Command=/usr/sbin/dbcheck -c
/etc/bacula/dir.conf -C Catalog -b -f
bacula-dir: runscript.c:290-0   --> Target=
bacula-dir: runscript.c:291-0   --> RunOnSuccess=1
bacula-dir: runscript.c:292-0   --> RunOnFailure=0
bacula-dir: runscript.c:293-0   --> FailJobOnError=1
bacula-dir: runscript.c:294-0   --> RunWhen=2
bacula-dir: runscript.c:287-0 runscript: debug
bacula-dir: runscript.c:288-0  --> RunScript
bacula-dir: runscript.c:289-0   --> Command=/usr/local/bin/mysqldumper.pl
bacula-dir: runscript.c:290-0   --> Target=
bacula-dir: runscript.c:291-0   --> RunOnSuccess=1
bacula-dir: runscript.c:292-0   --> RunOnFailure=0
bacula-dir: runscript.c:293-0   --> FailJobOnError=1
bacula-dir: runscript.c:294-0   --> RunWhen=2
bacula-dir: jcr.c:131-0 read_last_jobs seek to 192
bacula-dir: jcr.c:138-0 Read num_items=10
bacula-dir: dir_plugins.c:151-0 Load Director plugins
bacula-dir: dir_plugins.c:153-0 No Director plugin directory!
bacula-dir: mysql.c:119-0 db_init_database first time
bacula-dir: mysql.c:224-0 mysql_init done
bacula-dir: mysql.c:263-0 mysql_real_connect done
bacula-dir: mysql.c:265-0 db_user=bacula db_name=bacula db_password=***
bacula-dir: mysql.c:301-0 opendb ref=1 connected=1 db=af1240
bacula-dir: sql_create.c:324-0 In create mediatype
bacula-dir: sql_create.c:328-0 selectmediatype: SELECT
MediaTypeId,MediaType FROM MediaType WHERE MediaType='File'
bacula-dir: sql_create.c:324-0 In create mediatype
bacula-dir: sql_create.c:328-0 selectmediatype: SELECT
MediaTypeId,MediaType FROM MediaType WHERE MediaType='LTO-4'
bacula-dir: mysql.c:325-0 closedb ref=0 connected=1 db=af1240
bacula-dir: mysql.c:332-0 close db=af1240
minbar-dir: dird.c:359-0 Start UA server
minbar-dir: bnet_server.c:86-0 Addresses 0.0.0.0:9101
minbar-dir: job.c:1754-0 wstorage=babylon5-sd
minbar-dir: job.c:1763-0 wstore=babylon5-sd where=Pool resource
minbar-dir: job.c:1423-0 JobId=0 created
Job=*JobMonitor*.2017-08-01_16.32.33_01
minbar-dir: dird.c:373-0 wait for next job


Start BAT console:

minbar-dir: bnet.c:569-0 socket=6 who=client host=10.24.32.10 port=9101
minbar-dir: job.c:1754-0 wstorage=babylon5-sd
minbar-dir: job.c:1763-0 wstore=babylon5-sd where=Pool resource
minbar-dir: job.c:1423-0 JobId=0 created
Job=-Console-.2017-08-01_16.36.20_02
minbar-dir: cram-md5.c:69-0 send: auth cram-md5 challenge
<1432198243.1501619780@minbar-dir> ssl=0
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<366407527.1501619780@bat> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
r+/9izVBsHRQEA/yjV/aSA
minbar-dir: ua_dotcmds.c:177-0 Cmd: .api 1
minbar-dir: ua_dotcmds.c:177-0 Cmd: .messages
minbar-dir: ua_dotcmds.c:177-0 Cmd: .jobs
minbar-dir: ua_dotcmds.c:177-0 Cmd: .jobs type=R
minbar-dir: ua_dotcmds.c:177-0 Cmd: .clients
minbar-dir: ua_dotcmds.c:177-0 Cmd: .filesets
minbar-dir: ua_dotcmds.c:177-0 Cmd: .msgs
minbar-dir: ua_dotcmds.c:177-0 Cmd: .pools
minbar-dir: ua_dotcmds.c:177-0 Cmd: .storage
minbar-dir: ua_dotcmds.c:177-0 Cmd: .types
minbar-dir: ua_dotcmds.c:177-0 Cmd: .levels
minbar-dir: ua_dotcmds.c:177-0 Cmd: .volstatus
minbar-dir: ua_dotcmds.c:177-0 Cmd: .mediatypes
minbar-dir: ua_cmds.c:2541-0 UA Open database
minbar-dir: mysql.c:119-0 db_init_database first time
minbar-dir: mysql.c:224-0 mysql_init done
minbar-dir: mysql.c:263-0 mysql_real_connect done
minbar-dir: mysql.c:265-0 db_user=bacula db_name=bacula db_password=***
minbar-dir: mysql.c:301-0 opendb ref=1 connected=1 db=7ff004004230
minbar-dir: ua_cmds.c:2590-0 DB bacula opened
minbar-dir: ua_dotcmds.c:177-0 Cmd: .locations


STATUS STORAGE

Director:

minbar-dir: ua_dotcmds.c:177-0 Cmd: .sql query="SELECT Name AS
StorageName, StorageId AS ID, AutoChanger AS Changer FROM Storage  WHERE
StorageId IN (SELECT MAX(StorageId) FROM Storage WHERE Name IN
('asgard-file','babylon5-sd') GROUP BY Name) ORDER BY Name"
minbar-dir: ua_cmds.c:2541-0 UA Open database
minbar-dir: mysql.c:119-0 db_init_database first time
minbar-dir: mysql.c:224-0 mysql_init done
minbar-dir: mysql.c:263-0 mysql_real_connect done
minbar-dir: mysql.c:265-0 db_user=bacula db_name=bacula
db_password=IVantToSuckYourData
minbar-dir: mysql.c:301-0 opendb ref=1 connected=1 db=7ff00400e160
minbar-dir: ua_cmds.c:2590-0 DB bacula opened
minbar-dir: ua_dotcmds.c:177-0 Cmd: .status storage="asgard-file" terminated
minbar-dir: ua_status.c:58-0 status=".status storage="asgard-file"
terminated" argc=3
minbar-dir: job.c:1788-0 wstore=asgard-file where=unknown source
minbar-dir: msgchan.c:120-0 Connect to Storage daemon
asgard.caerllewys.net:9103
minbar-dir: bsock.c:237-0 Current 10.24.32.6:9103 All 10.24.32.6:9103
minbar-dir: bsock.c:166-0 who=Storage daemon host=asgard.caerllewys.net
port=9103
minbar-dir: bsock.c:349-0 OK connected to server  Storage daemon
asgard.caerllewys.net:9103.
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<1257395030.1501619846@asgard-sd> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
W94Qd6+WS6YIh4/Y89+3IC
minbar-dir: cram-md5.c:76-0 send: auth cram-md5 challenge
<72130288.1501619846@minbar-dir> ssl=0
minbar-dir: cram-md5.c:95-0 Authenticate OK tC+r74/ulFUuq+Uty6ZXQB
minbar-dir: authenticate.c:155-0 >stored: 1000 OK auth
minbar-dir: authenticate.c:162-0 <stored: 3000 OK Hello 306
minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_dotcmds.c:177-0 Cmd: .status storage="babylon5-sd" terminated
minbar-dir: ua_status.c:58-0 status=".status storage="babylon5-sd"
terminated" argc=3
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source
minbar-dir: msgchan.c:120-0 Connect to Storage daemon
babylon5.babcom.com:9103
minbar-dir: bsock.c:237-0 Current 10.24.32.10:9103 All 10.24.32.10:9103
minbar-dir: bsock.c:166-0 who=Storage daemon host=babylon5.babcom.com
port=9103
minbar-dir: bsock.c:349-0 OK connected to server  Storage daemon
babylon5.babcom.com:9103.
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<577275131.1501619847@babylon5-sd> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
D//Xt74Sc8+0AHIEN4tUkD
minbar-dir: cram-md5.c:76-0 send: auth cram-md5 challenge
<1288394884.1501619847@minbar-dir> ssl=0
minbar-dir: cram-md5.c:95-0 Authenticate OK T0/5km8pFT+w1CJ845/bsB
minbar-dir: authenticate.c:155-0 >stored: 1000 OK auth
minbar-dir: authenticate.c:162-0 <stored: 3000 OK Hello 306
minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_dotcmds.c:177-0 Cmd: .status storage="babylon5-sd" terminated
minbar-dir: ua_status.c:58-0 status=".status storage="babylon5-sd"
terminated" argc=3
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source
minbar-dir: msgchan.c:120-0 Connect to Storage daemon
babylon5.babcom.com:9103
minbar-dir: bsock.c:237-0 Current 10.24.32.10:9103 All 10.24.32.10:9103
minbar-dir: bsock.c:166-0 who=Storage daemon host=babylon5.babcom.com
port=9103
minbar-dir: bsock.c:349-0 OK connected to server  Storage daemon
babylon5.babcom.com:9103.
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<1179401143.1501619850@babylon5-sd> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
I2tHU6tD81cvD9gYz+4IGD
minbar-dir: cram-md5.c:76-0 send: auth cram-md5 challenge
<2092306401.1501619850@minbar-dir> ssl=0
minbar-dir: cram-md5.c:95-0 Authenticate OK y6BpZU/fb++zi3+QSAAFYA
minbar-dir: authenticate.c:155-0 >stored: 1000 OK auth
minbar-dir: authenticate.c:162-0 <stored: 3000 OK Hello 306
minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_dotcmds.c:177-0 Cmd: .status storage="babylon5-sd" terminated
minbar-dir: ua_status.c:58-0 status=".status storage="babylon5-sd"
terminated" argc=3
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source
minbar-dir: msgchan.c:120-0 Connect to Storage daemon
babylon5.babcom.com:9103
minbar-dir: bsock.c:237-0 Current 10.24.32.10:9103 All 10.24.32.10:9103
minbar-dir: bsock.c:166-0 who=Storage daemon host=babylon5.babcom.com
port=9103
minbar-dir: bsock.c:349-0 OK connected to server  Storage daemon
babylon5.babcom.com:9103.
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<627223309.1501619878@babylon5-sd> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
u2I34h+Kn/+lE+IlHH+5CC
minbar-dir: cram-md5.c:76-0 send: auth cram-md5 challenge
<1890065295.1501619878@minbar-dir> ssl=0
minbar-dir: cram-md5.c:95-0 Authenticate OK 469H+E+fG5/5Sl+GSj/JxD
minbar-dir: authenticate.c:155-0 >stored: 1000 OK auth
minbar-dir: authenticate.c:162-0 <stored: 3000 OK Hello 306
minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_dotcmds.c:177-0 Cmd: .status storage="babylon5-sd" terminated
minbar-dir: ua_status.c:58-0 status=".status storage="babylon5-sd"
terminated" argc=3
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source


Storage:

babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:37:27
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<577275131.1501619847@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<1288394884.1501619847@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
T0/5km8pFT+w1CJ845/bsB
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated
babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:37:30
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<1179401143.1501619850@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<2092306401.1501619850@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
y6BpZU/fb++zi3+QSAAFYA
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated
babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:37:58
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<627223309.1501619878@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<1890065295.1501619878@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
469H+E+fG5/5Sl+GSj/JxD
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated
babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:38:26
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<202876595.1501619906@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<1518734085.1501619906@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
/3BrD9cXd448WB/j/7+NwA
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated
babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:38:54
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<1972434777.1501619934@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<360204182.1501619934@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
Q7/4EHU2l8+NX4+Xj4swXC
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated
babylon5-sd: bnet.c:569-0 socket=6 who=client host=10.24.32.15 port=9103
babylon5-sd: dircmd.c:188-0 Got a DIR connection at 01-Aug-2017 16:39:22
babylon5-sd: cram-md5.c:69-0 send: auth cram-md5 challenge
<1808265894.1501619962@babylon5-sd> ssl=0
babylon5-sd: cram-md5.c:133-0 cram-get received: auth cram-md5
<1325444403.1501619962@minbar-dir> ssl=0
babylon5-sd: cram-md5.c:157-0 sending resp to challenge:
a0+ns6/8+A+H65/jM6U7jD
babylon5-sd: dircmd.c:214-0 Message channel init completed.
babylon5-sd: dircmd.c:223-0 <dird: .status terminated api=1 api_opts=
babylon5-sd: dircmd.c:237-0 Do command: .status
babylon5-sd: status.c:1063-0 cmd=terminated


UMOUNT STORAGE=babylon5-sd

Director log:

minbar-dir: msgchan.c:120-0 Connect to Storage daemon
babylon5.babcom.com:9103
minbar-dir: bsock.c:237-0 Current 10.24.32.10:9103 All 10.24.32.10:9103
minbar-dir: bsock.c:166-0 who=Storage daemon host=babylon5.babcom.com
port=9103
minbar-dir: bsock.c:349-0 OK connected to server  Storage daemon
babylon5.babcom.com:9103.
minbar-dir: cram-md5.c:133-0 cram-get received: auth cram-md5
<895104008.1501620046@babylon5-sd> ssl=0
minbar-dir: cram-md5.c:157-0 sending resp to challenge:
G6NRC8/xT9+qUl+kTj/6eB
minbar-dir: cram-md5.c:76-0 send: auth cram-md5 challenge
<1893667383.1501620046@minbar-dir> ssl=0
minbar-dir: cram-md5.c:95-0 Authenticate OK i4/g92Em34IS3F/Lm7ZBfD
minbar-dir: authenticate.c:155-0 >stored: 1000 OK auth
minbar-dir: authenticate.c:162-0 <stored: 3000 OK Hello 306
minbar-dir: ua_status.c:552-0 Connected to storage daemon
minbar-dir: ua_cmds.c:1731-0 unmount: umount storage=babylon5-sd
minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source

Storage log:

NOTHING - No command received



--
  Phil Stracchino
  Babylon Communications
  [hidden email]
  [hidden email]
  Landline: +1.603.293.8485
  Mobile:   +1.603.998.6958

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-devel
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Daemon logs -d 200: storage unload, 9.0.3 with standalone tape drive

Martin Simmons
>>>>> On Tue, 1 Aug 2017 16:58:33 -0400, Phil Stracchino said:
>
> Sorry for the length.  This is a complete log history from starting the
> SD (with a tape already loaded) and the director, starting a BAT, doing
> a STATUS STORAGE, then an UMOUNT STORAGE=babylon5-sd, all at -d 200.
>
>
> Summary:
>
> When the STATUS STORAGE is issued, the Director talks to the SD, the SD
> replies, the Director posts the results.  All perfectly normal.
>
> When the UMOUNT STORAGE is issued, the director sends the unmount command:
>
> minbar-dir: ua_status.c:552-0 Connected to storage daemon
> minbar-dir: ua_cmds.c:1731-0 unmount: umount storage=babylon5-sd
> minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source
>
> The SD receives *nothing*, does *nothing*, and logs *nothing*.  It
> appears the SD does not receive either mount or umount commands.
> Status, however, works, as do reads and writes.  I haven't tested LABEL.

Does it work if you pass slot=0 in the command?

umount storage=babylon5-sd slot=0

__Martin

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-devel
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Daemon logs -d 200: storage unload, 9.0.3 with standalone tape drive

Phil Stracchino-2
On 08/02/17 06:32, Martin Simmons wrote:

>>>>>> On Tue, 1 Aug 2017 16:58:33 -0400, Phil Stracchino said:
>>
>> Sorry for the length.  This is a complete log history from starting the
>> SD (with a tape already loaded) and the director, starting a BAT, doing
>> a STATUS STORAGE, then an UMOUNT STORAGE=babylon5-sd, all at -d 200.
>>
>>
>> Summary:
>>
>> When the STATUS STORAGE is issued, the Director talks to the SD, the SD
>> replies, the Director posts the results.  All perfectly normal.
>>
>> When the UMOUNT STORAGE is issued, the director sends the unmount command:
>>
>> minbar-dir: ua_status.c:552-0 Connected to storage daemon
>> minbar-dir: ua_cmds.c:1731-0 unmount: umount storage=babylon5-sd
>> minbar-dir: job.c:1788-0 wstore=babylon5-sd where=unknown source
>>
>> The SD receives *nothing*, does *nothing*, and logs *nothing*.  It
>> appears the SD does not receive either mount or umount commands.
>> Status, however, works, as do reads and writes.  I haven't tested LABEL.
>
> Does it work if you pass slot=0 in the command?
>
> umount storage=babylon5-sd slot=0



Martin,
Yes, it does.  Thank you for that suggestion.  Both mount and unmount
work, *IF AND ONLY IF* slot=0 is specified.  I did not think to try
that, as it has never been needed for a standalone drive before 9.0.

Apparently the slot argument is now mandatory, and BAT does not send it.
 Why the command is not sent to the Storage by the Director unless the
slot is specified is a mystery to me.

I've just updated bug #2300 with this additional information.



--
  Phil Stracchino
  Babylon Communications
  [hidden email]
  [hidden email]
  Landline: +1.603.293.8485
  Mobile:   +1.603.998.6958

------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
Bacula-devel mailing list
[hidden email]
https://lists.sourceforge.net/lists/listinfo/bacula-devel
Loading...