MHVTL with HP DataProtector 6.11

classic Classic list List threaded Threaded
Locked 1 message Options
Reply | Threaded
Open this post in threaded view
|

MHVTL with HP DataProtector 6.11

[nia]
Administrator

MHVTL with HP DataProtector 6.11

Postby xirman » Wed Jun 23, 2010 7:13 am

Following configuration was tested:

CentOS 5.5 x86_64 (2.6.18-194.3.1.el5):
mhvtl-0.16
DataProtector 6.11 (A.06.11) with pathes

/etc/mhvtl/device.conf

Library: 10 CHANNEL: 00 TARGET: 00 LUN: 00
Vendor identification: IBM
Product identification: ULT3583-TL
Product revision level: 550V
Unit serial number: XYZZY_A
NAA: 10:22:33:44:ab:00:00:00

Drive: 11 CHANNEL: 00 TARGET: 01 LUN: 00
Library ID: 10 Slot: 01
Vendor identification: IBM
Product identification: ULT3580-TD4
Product revision level: 550V
Unit serial number: XYZZY_A1
NAA: 10:22:33:44:ab:00:01:00
Compression: factor 1 enabled 0

Drive: 12 CHANNEL: 00 TARGET: 02 LUN: 00
Library ID: 10 Slot: 02
Vendor identification: IBM
Product identification: ULT3580-TD4
Product revision level: 550V
Unit serial number: XYZZY_A2
NAA: 10:22:33:44:ab:00:02:00
Compression: factor 1 enabled 0

----------------------------
Trying autoconfigure libraries, but for FIRTS time not succeed. DP configure only drives, library reported as not having drives.
Second attempt was success, DP correctly recognize Library and attached drives.
It seems it is some notion of HP DP to recognize library ate second attempt every time.
Anyway other libraries like SPECTRA:PYTHON was not recognized at all.
DP used this library in direct mode.

Everything was working fine except ONE big thing THE PERFORMANCE.
Tested where different configs with “Compression: factor” and “enabled” values set to different values.
Because performance is a big issue to make mhvtl usable program I decided to take much closer look for this problem and than test with ancient TAR program.
Because TAR is no DP exercises will continue in separate posts
xirman
Registered
 
Posts: 1
Joined: Wed Jun 23, 2010 6:42 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Wed Jun 23, 2010 9:40 pm

Please note:

Performance was NEVER a design criteria for this VTL.
Its design criteria was to function as close as possible to real hardware.

However, that out of the way, actual performance testing shows anywhere from 10Mbytes/sec (operating within VMWare guest) to 30+MBytes/sec on native hardware.
Nothing like the 80+MBytes/sec real tape drives are achieving now days.
Note: Performance measurements using NetBackup.

Cheers
Mark
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby cup » Mon Aug 02, 2010 3:14 am

Hi,

I tried mhvtl 0.18-9 at Centos 5.5 with Data Protector 6.11, everything is fine until I try to perform a restore that the tape has more than one backup, I tried to restore the latest image which is located in the middle of the tape, error occurred:

[Critical] From: [hidden email] "IBM:ULT3580-TD4_1_pilots" Time: 2/8/2010 15:12:53
[90:186] Lost position. (Inconsistent/Lost position information.)

[Major] From: [hidden email] "IBM:ULT3580-TD4_1_pilots" Time: 2/8/2010 15:12:53
[90:53] /dev/nst0
Cannot seek to requested position (Inconsistent/Lost position information.)

My device.conf:
Library: 10 CHANNEL: 00 TARGET: 00 LUN: 00
Vendor identification: IBM
Product identification: ULT3583-TL
Product revision level: 550V
Unit serial number: XYZZY_A
NAA: 10:22:33:44:ab:00:00:00

Drive: 11 CHANNEL: 00 TARGET: 01 LUN: 00
Library ID: 10 Slot: 01
Vendor identification: IBM
Product identification: ULT3580-TD4
Product revision level: 550V
Unit serial number: XYZZY_A1
NAA: 10:22:33:44:ab:00:01:00
Compression: factor 1 enabled 0

Drive: 12 CHANNEL: 00 TARGET: 02 LUN: 00
Library ID: 10 Slot: 02
Vendor identification: IBM
Product identification: ULT3580-TD4
Product revision level: 550V
Unit serial number: XYZZY_A2
NAA: 10:22:33:44:ab:00:02:00
Compression: factor 1 enabled 0


And my library_contents.10:
Slot 1: DD1001L4
Slot 2: DD1002L4
Slot 3: DD1003L4
Slot 4: DD1004L4
Slot 5: DD1005L4
Slot 6: DD1006L4
Slot 7: DD1007L4
Slot 8: DD1008L4
Slot 9: DD1009L4
Slot 10: DD1010L4

Any hints ? Thanks in advance.
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Mon Aug 02, 2010 6:54 pm

I can't help with data protector, however several things can be run to see if the tape is in the expected format:

Supplied with the source is a utility called 'dump_tape'

Usage is: dump_tape -f DD1001L4
This utility will dump out the headers & size of each data block.
Confirm the tape format is what you would expect with a real tape.

Can you please enable verbose logging (/etc/mhvtl/mhvtl.conf and set VERBOSE = 2)
Supply the syslog (typically /var/log/messages), for the time frame when you attempt the restore Along with the dump_tape output.


An empty media dump will look something like
# ./dump_tape -f L43001L4
PCL is : L43001L4
Media density code: 0x46
Media type code : 0x08
Media description : Ultrium 4/8T
Tape Capacity : 524288000
Hdr: End of Data(05), sz 0, Blk No.: 0, data 0

Cheers
Mark
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby cup » Mon Aug 02, 2010 9:49 pm

Hi, the dump_tape output for the tape with 2 full backups:

CODE: SELECT ALL
/usr/src/redhat/BUILD/mhvtl-0.18/usr/dump_tape -f DD1001L4
PCL is : DD1001L4
Media density code: 0x46
Media type code   : 0x08
Media description : Ultrium 4/8T
Tape Capacity     : 1048576000
Hdr:             data(0b), sz   8192/8192  , Blk No.: 0, data 0
Hdr:             data(0b), sz  65536/65536 , Blk No.: 1, data 8192
Hdr:         Filemark(03), sz             0, Blk No.: 2, data 73728
Hdr:             data(0b), sz  65536/65536 , Blk No.: 3, data 73728
Hdr:             data(0b), sz  65536/65536 , Blk No.: 4, data 139264
Hdr:             data(0b), sz  65536/65536 , Blk No.: 5, data 204800
Hdr:             data(0b), sz  65536/65536 , Blk No.: 6, data 270336
Hdr:             data(0b), sz  65536/65536 , Blk No.: 7, data 335872
Hdr:             data(0b), sz  65536/65536 , Blk No.: 8, data 401408
Hdr:             data(0b), sz  65536/65536 , Blk No.: 9, data 466944
Hdr:             data(0b), sz  65536/65536 , Blk No.: 10, data 532480
Hdr:             data(0b), sz  65536/65536 , Blk No.: 11, data 598016
Hdr:             data(0b), sz  65536/65536 , Blk No.: 12, data 663552
Hdr:             data(0b), sz  65536/65536 , Blk No.: 13, data 729088
Hdr:             data(0b), sz  65536/65536 , Blk No.: 14, data 794624
Hdr:             data(0b), sz  65536/65536 , Blk No.: 15, data 860160
Hdr:             data(0b), sz  65536/65536 , Blk No.: 16, data 925696
Hdr:             data(0b), sz  65536/65536 , Blk No.: 17, data 991232
Hdr:             data(0b), sz  65536/65536 , Blk No.: 18, data 1056768
Hdr:             data(0b), sz  65536/65536 , Blk No.: 19, data 1122304
Hdr:             data(0b), sz  65536/65536 , Blk No.: 20, data 1187840
Hdr:             data(0b), sz  65536/65536 , Blk No.: 21, data 1253376
Hdr:             data(0b), sz  65536/65536 , Blk No.: 22, data 1318912
Hdr:             data(0b), sz  65536/65536 , Blk No.: 23, data 1384448
Hdr:             data(0b), sz  65536/65536 , Blk No.: 24, data 1449984
Hdr:             data(0b), sz  65536/65536 , Blk No.: 25, data 1515520
Hdr:             data(0b), sz  65536/65536 , Blk No.: 26, data 1581056
Hdr:             data(0b), sz  65536/65536 , Blk No.: 27, data 1646592
Hdr:             data(0b), sz  65536/65536 , Blk No.: 28, data 1712128
Hdr:             data(0b), sz  65536/65536 , Blk No.: 29, data 1777664
Hdr:             data(0b), sz  65536/65536 , Blk No.: 30, data 1843200
Hdr:             data(0b), sz  65536/65536 , Blk No.: 31, data 1908736
Hdr:             data(0b), sz  65536/65536 , Blk No.: 32, data 1974272
Hdr:             data(0b), sz  65536/65536 , Blk No.: 33, data 2039808
Hdr:             data(0b), sz  65536/65536 , Blk No.: 34, data 2105344
Hdr:             data(0b), sz  65536/65536 , Blk No.: 35, data 2170880
Hdr:             data(0b), sz  65536/65536 , Blk No.: 36, data 2236416
Hdr:             data(0b), sz  65536/65536 , Blk No.: 37, data 2301952
Hdr:             data(0b), sz  65536/65536 , Blk No.: 38, data 2367488
Hdr:             data(0b), sz  65536/65536 , Blk No.: 39, data 2433024
Hdr:             data(0b), sz  65536/65536 , Blk No.: 40, data 2498560
Hdr:             data(0b), sz  65536/65536 , Blk No.: 41, data 2564096
Hdr:             data(0b), sz  65536/65536 , Blk No.: 42, data 2629632
Hdr:             data(0b), sz  65536/65536 , Blk No.: 43, data 2695168
Hdr:             data(0b), sz  65536/65536 , Blk No.: 44, data 2760704
Hdr:             data(0b), sz  65536/65536 , Blk No.: 45, data 2826240
Hdr:             data(0b), sz  65536/65536 , Blk No.: 46, data 2891776
Hdr:             data(0b), sz  65536/65536 , Blk No.: 47, data 2957312
Hdr:             data(0b), sz  65536/65536 , Blk No.: 48, data 3022848
Hdr:             data(0b), sz  65536/65536 , Blk No.: 49, data 3088384
Hdr:             data(0b), sz  65536/65536 , Blk No.: 50, data 3153920
Hdr:             data(0b), sz  65536/65536 , Blk No.: 51, data 3219456
Hdr:             data(0b), sz  65536/65536 , Blk No.: 52, data 3284992
Hdr:             data(0b), sz  65536/65536 , Blk No.: 53, data 3350528
Hdr:             data(0b), sz  65536/65536 , Blk No.: 54, data 3416064
Hdr:             data(0b), sz  65536/65536 , Blk No.: 55, data 3481600
Hdr:             data(0b), sz  65536/65536 , Blk No.: 56, data 3547136
Hdr:             data(0b), sz  65536/65536 , Blk No.: 57, data 3612672
Hdr:             data(0b), sz  65536/65536 , Blk No.: 58, data 3678208
Hdr:             data(0b), sz  65536/65536 , Blk No.: 59, data 3743744
Hdr:             data(0b), sz  65536/65536 , Blk No.: 60, data 3809280
Hdr:             data(0b), sz  65536/65536 , Blk No.: 61, data 3874816
Hdr:         Filemark(03), sz             0, Blk No.: 62, data 3940352
Hdr:             data(0b), sz  65536/65536 , Blk No.: 63, data 3940352
Hdr:         Filemark(03), sz             0, Blk No.: 64, data 4005888
Hdr:             data(0b), sz  65536/65536 , Blk No.: 65, data 4005888
Hdr:             data(0b), sz  65536/65536 , Blk No.: 66, data 4071424
Hdr:             data(0b), sz  65536/65536 , Blk No.: 67, data 4136960
Hdr:             data(0b), sz  65536/65536 , Blk No.: 68, data 4202496
Hdr:             data(0b), sz  65536/65536 , Blk No.: 69, data 4268032
Hdr:             data(0b), sz  65536/65536 , Blk No.: 70, data 4333568
Hdr:             data(0b), sz  65536/65536 , Blk No.: 71, data 4399104
Hdr:             data(0b), sz  65536/65536 , Blk No.: 72, data 4464640
Hdr:             data(0b), sz  65536/65536 , Blk No.: 73, data 4530176
Hdr:             data(0b), sz  65536/65536 , Blk No.: 74, data 4595712
Hdr:             data(0b), sz  65536/65536 , Blk No.: 75, data 4661248
Hdr:             data(0b), sz  65536/65536 , Blk No.: 76, data 4726784
Hdr:             data(0b), sz  65536/65536 , Blk No.: 77, data 4792320
Hdr:             data(0b), sz  65536/65536 , Blk No.: 78, data 4857856
Hdr:             data(0b), sz  65536/65536 , Blk No.: 79, data 4923392
Hdr:             data(0b), sz  65536/65536 , Blk No.: 80, data 4988928
Hdr:             data(0b), sz  65536/65536 , Blk No.: 81, data 5054464
Hdr:             data(0b), sz  65536/65536 , Blk No.: 82, data 5120000
Hdr:             data(0b), sz  65536/65536 , Blk No.: 83, data 5185536
Hdr:             data(0b), sz  65536/65536 , Blk No.: 84, data 5251072
Hdr:             data(0b), sz  65536/65536 , Blk No.: 85, data 5316608
Hdr:             data(0b), sz  65536/65536 , Blk No.: 86, data 5382144
Hdr:             data(0b), sz  65536/65536 , Blk No.: 87, data 5447680
Hdr:             data(0b), sz  65536/65536 , Blk No.: 88, data 5513216
Hdr:             data(0b), sz  65536/65536 , Blk No.: 89, data 5578752
Hdr:             data(0b), sz  65536/65536 , Blk No.: 90, data 5644288
Hdr:             data(0b), sz  65536/65536 , Blk No.: 91, data 5709824
Hdr:             data(0b), sz  65536/65536 , Blk No.: 92, data 5775360
Hdr:             data(0b), sz  65536/65536 , Blk No.: 93, data 5840896
Hdr:             data(0b), sz  65536/65536 , Blk No.: 94, data 5906432
Hdr:             data(0b), sz  65536/65536 , Blk No.: 95, data 5971968
Hdr:             data(0b), sz  65536/65536 , Blk No.: 96, data 6037504
Hdr:             data(0b), sz  65536/65536 , Blk No.: 97, data 6103040
Hdr:             data(0b), sz  65536/65536 , Blk No.: 98, data 6168576
Hdr:             data(0b), sz  65536/65536 , Blk No.: 99, data 6234112
Hdr:             data(0b), sz  65536/65536 , Blk No.: 100, data 6299648
Hdr:             data(0b), sz  65536/65536 , Blk No.: 101, data 6365184
Hdr:             data(0b), sz  65536/65536 , Blk No.: 102, data 6430720
Hdr:             data(0b), sz  65536/65536 , Blk No.: 103, data 6496256
Hdr:             data(0b), sz  65536/65536 , Blk No.: 104, data 6561792
Hdr:             data(0b), sz  65536/65536 , Blk No.: 105, data 6627328
Hdr:             data(0b), sz  65536/65536 , Blk No.: 106, data 6692864
Hdr:             data(0b), sz  65536/65536 , Blk No.: 107, data 6758400
Hdr:             data(0b), sz  65536/65536 , Blk No.: 108, data 6823936
Hdr:             data(0b), sz  65536/65536 , Blk No.: 109, data 6889472
Hdr:             data(0b), sz  65536/65536 , Blk No.: 110, data 6955008
Hdr:             data(0b), sz  65536/65536 , Blk No.: 111, data 7020544
Hdr:             data(0b), sz  65536/65536 , Blk No.: 112, data 7086080
Hdr:             data(0b), sz  65536/65536 , Blk No.: 113, data 7151616
Hdr:             data(0b), sz  65536/65536 , Blk No.: 114, data 7217152
Hdr:             data(0b), sz  65536/65536 , Blk No.: 115, data 7282688
Hdr:             data(0b), sz  65536/65536 , Blk No.: 116, data 7348224
Hdr:             data(0b), sz  65536/65536 , Blk No.: 117, data 7413760
Hdr:             data(0b), sz  65536/65536 , Blk No.: 118, data 7479296
Hdr:             data(0b), sz  65536/65536 , Blk No.: 119, data 7544832
Hdr:             data(0b), sz  65536/65536 , Blk No.: 120, data 7610368
Hdr:             data(0b), sz  65536/65536 , Blk No.: 121, data 7675904
Hdr:             data(0b), sz  65536/65536 , Blk No.: 122, data 7741440
Hdr:             data(0b), sz  65536/65536 , Blk No.: 123, data 7806976
Hdr:             data(0b), sz  65536/65536 , Blk No.: 124, data 7872512
Hdr:         Filemark(03), sz             0, Blk No.: 125, data 7938048
Hdr:             data(0b), sz  65536/65536 , Blk No.: 126, data 7938048
Hdr:         Filemark(03), sz             0, Blk No.: 127, data 8003584
Hdr:         Filemark(03), sz             0, Blk No.: 128, data 8003584
Hdr:      End of Data(05), sz             0, Blk No.: 129, data 8003584


And the log syslog messages when for the failed restore session:
CODE: SELECT ALL
Aug  3 09:45:31 pilots xinetd[2483]: START: omni pid=11383 from=127.0.0.1
Aug  3 09:45:31 pilots xinetd[2483]: EXIT: omni status=0 pid=11383 duration=0(sec)
Aug  3 09:45:31 pilots xinetd[2483]: START: omni pid=11384 from=127.0.0.1
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17016) 12 00 00 00 ff 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17016), sz: 66, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17017) 1a 00 1d 00 ff 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: MODE SENSE **
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Mode Sense 6 byte version
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Page Code     : 0x1d
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Disable Block Descriptor => No
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Allocation len: 255
Aug  3 09:45:31 pilots vtllibrary[11103]: find_pcode: (0x1d): match pcode 29
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17017), sz: 32, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17018) 12 00 00 00 ff 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17018), sz: 66, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17019) 00 00 00 00 00 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17019), sz: 0, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17020) 1a 00 1d 00 ff 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: MODE SENSE **
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Mode Sense 6 byte version
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Page Code     : 0x1d
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Disable Block Descriptor => No
Aug  3 09:45:31 pilots vtllibrary[11103]: resp_mode_sense:  Allocation len: 255
Aug  3 09:45:31 pilots vtllibrary[11103]: find_pcode: (0x1d): match pcode 29
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17020), sz: 32, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17021) 00 00 00 00 00 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17021), sz: 0, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17022) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: READ ELEMENT STATUS **
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_page: Slot: 1
Aug  3 09:45:31 pilots vtllibrary[11103]: slot2struct: slot2struct: Drive 1
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_descriptor: Slot location: 1
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17022), sz: 32, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17023) b8 02 04 00 00 01 00 00 00 ff 00 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: READ ELEMENT STATUS **
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_page: Slot: 1024
Aug  3 09:45:31 pilots vtllibrary[11103]: slot2struct: slot2struct: Storage 1024
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_descriptor: Slot location: 1024
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Starting slot: 1024, number of configured slots: 1
Aug  3 09:45:31 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 00 00 01 00 00 00 18
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17023), sz: 32, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17024) 12 00 00 00 ff 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:31 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17024), sz: 66, sam_status: 0
Aug  3 09:45:31 pilots vtllibrary[11103]: CDB (17025) a5 00 00 00 04 00 00 01 00 00 00 00
Aug  3 09:45:31 pilots vtllibrary[11103]: processCommand: MOVE MEDIUM **
Aug  3 09:45:31 pilots vtllibrary[11103]: Moving from slot 1024 to Slot 1 using transport 0, Invert media: no
Aug  3 09:45:31 pilots vtllibrary[11103]: slot2struct: slot2struct: Storage 1024
Aug  3 09:45:31 pilots vtllibrary[11103]: move_slot2drive: About to send cmd: 'lload DD1001L4' to drive 11
Aug  3 09:45:32 pilots vtltape[10967]: processMessageQ: Q snd_id 10 msg : lload DD1001L4
Aug  3 09:45:32 pilots vtltape[10967]: load_tape: Opening file/media /opt/mhvtl/DD1001L4
Aug  3 09:45:32 pilots vtltape[10967]: loadTape: MAM: media S/No. DD1001L4_1280799618
Aug  3 09:45:32 pilots vtltape[10967]: find_pcode: (0x1d): match pcode 29
Aug  3 09:45:32 pilots vtltape[10967]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [06 28 00]
Aug  3 09:45:32 pilots vtltape[10967]: loadTape: Tape capacity: 1048576000
Aug  3 09:45:32 pilots vtltape[10967]: updateMAM: updateMAM(1)
Aug  3 09:45:32 pilots vtltape[10967]: loadTape: Supported media list is empty, loading media
Aug  3 09:45:32 pilots vtltape[10967]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:32 pilots vtltape[10967]: loadTape: Media is writable
Aug  3 09:45:32 pilots vtltape[10967]: loadTape: Setting MediumDensityCode to 0x46
Aug  3 09:45:32 pilots vtltape[10967]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:32 pilots vtllibrary[11103]: check_tape_load: Received "Loaded OK: DD1001L4 " from message Q
Aug  3 09:45:32 pilots vtllibrary[11103]: is_map_slot: slot type 4
Aug  3 09:45:32 pilots vtllibrary[11103]: check_tape_load: Received "Loaded OK: DD1001L4 " from message Q
Aug  3 09:45:32 pilots vtllibrary[11103]: is_map_slot: slot type 4
Aug  3 09:45:32 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17025), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17026) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Test Unit Ready (17026) : Yes
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17026), sz: 0, sam_status: 2
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17027) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Test Unit Ready (17027) : Yes
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17027), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17028) 05 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Read block limits (17028) **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17028), sz: 6, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17029) 1a 00 00 00 0c 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: MODE SENSE (17029) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Mode Sense 6 byte version
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Page Code     : 0x0
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Disable Block Descriptor => No
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Allocation len: 12
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17029), sz: 12, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17030) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Test Unit Ready (17030) : Yes
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17030), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17031) 05 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Read block limits (17031) **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17031), sz: 6, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17032) 1a 00 00 00 0c 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: MODE SENSE (17032) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Mode Sense 6 byte version
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Page Code     : 0x0
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Disable Block Descriptor => No
Aug  3 09:45:35 pilots vtltape[10967]: resp_mode_sense:  Allocation len: 12
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17032), sz: 12, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17033) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: INQUIRY (17033) **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17033), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17034) 01 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Rewinding (17034) **
Aug  3 09:45:35 pilots vtltape[10967]: rewind_tape: Media is writable
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17034), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17035) a2 20 00 10 00 00 00 00 00 ff 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Security Protocol In (17035) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: Data Encryption Capabilities page
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: Drive type: 4, Media type: 8
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: LTO4 drive
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: LTO4 Medium
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17035), sz: 44, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17036) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Security Protocol In (17036) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: Data Encryption Status page
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17036), sz: 24, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17037) 08 00 00 20 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: READ_6 (17037) : 8192 bytes **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17037), sz: 8192, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17038) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: INQUIRY (17038) **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17038), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17039) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: LOG SENSE (17039) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug  3 09:45:35 pilots vtltape[10967]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17039), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17040) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17040), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17041) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17041), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17042) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: LOG SENSE **
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17042) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: LOG SENSE **
Aug  3 09:45:35 pilots vtllibrary[11103]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtllibrary[11103]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17042), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17043) 11 01 00 00 03 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: SPACE (17043) ** 3 filemarks
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17043), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17044) 08 00 01 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: READ_6 (17044) : 65536 bytes **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17044), sz: 65536, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17045) 11 00 ff ff ff 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: SPACE (17045) ** 16777215 blocks
Aug  3 09:45:35 pilots vtltape[10967]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [80 00 01]
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17045), sz: 0, sam_status: 2
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17046) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: LOG SENSE (17046) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug  3 09:45:35 pilots vtltape[10967]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17046), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17047) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17047), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17048) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17048), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17049) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: LOG SENSE **
Aug  3 09:45:35 pilots vtllibrary[11103]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtllibrary[11103]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17049), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17050) 01 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Rewinding (17050) **
Aug  3 09:45:35 pilots vtltape[10967]: rewind_tape: Media is writable
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17050), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17051) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: LOG SENSE (17051) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtltape[10967]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug  3 09:45:35 pilots vtltape[10967]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17051), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17052) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17052), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17053) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17053), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17054) 4d 00 2e 00 00 00 00 01 44 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: LOG SENSE **
Aug  3 09:45:35 pilots vtllibrary[11103]: resp_log_sense: LOG SENSE: TapeAlert page
Aug  3 09:45:35 pilots vtllibrary[11103]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17054), sz: 324, sam_status: 0
Aug  3 09:45:35 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17055) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Security Protocol In (17055) **
Aug  3 09:45:35 pilots vtltape[10967]: resp_spin_page_20: Data Encryption Status page
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17055), sz: 24, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: CDB (17056) 1b 00 00 00 00 00
Aug  3 09:45:35 pilots vtltape[10967]: updateMAM: updateMAM(0)
Aug  3 09:45:35 pilots vtltape[10967]: find_pcode: (0x1d): match pcode 29
Aug  3 09:45:35 pilots vtltape[10967]: clearWORM: WORM mode page cleared
Aug  3 09:45:35 pilots vtltape[10967]: processCommand: Unloading Tape (17056)  **
Aug  3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17056), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17057) 00 00 00 00 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17057), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17058) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: READ ELEMENT STATUS **
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_page: Slot: 1
Aug  3 09:45:35 pilots vtllibrary[11103]: slot2struct: slot2struct: Drive 1
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_descriptor: Slot location: 1
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17058), sz: 32, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17059) b8 02 04 00 00 01 00 00 00 ff 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: READ ELEMENT STATUS **
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_page: Slot: 1024
Aug  3 09:45:35 pilots vtllibrary[11103]: slot2struct: slot2struct: Storage 1024
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_descriptor: Slot location: 1024
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Starting slot: 1024, number of configured slots: 1
Aug  3 09:45:35 pilots vtllibrary[11103]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 00 00 01 00 00 00 18
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17059), sz: 32, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17060) 12 00 00 00 ff 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: INQUIRY **
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17060), sz: 66, sam_status: 0
Aug  3 09:45:35 pilots vtllibrary[11103]: CDB (17061) a5 00 00 00 00 01 04 00 00 00 00 00
Aug  3 09:45:35 pilots vtllibrary[11103]: processCommand: MOVE MEDIUM **
Aug  3 09:45:35 pilots vtllibrary[11103]: Moving from slot 1 to Slot 1024 using transport 0, Invert media: no
Aug  3 09:45:35 pilots vtllibrary[11103]: slot2struct: slot2struct: Storage 1024
Aug  3 09:45:35 pilots vtllibrary[11103]: is_map_slot: slot type 2
Aug  3 09:45:35 pilots vtllibrary[11103]: is_map_slot: slot type 2
Aug  3 09:45:35 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17061), sz: 0, sam_status: 0
Aug  3 09:45:35 pilots vtltape[10967]: processMessageQ: Q snd_id 10 msg : unload
Aug  3 09:45:35 pilots vtltape[10967]: unloadTape: Tape not mounted
Aug  3 09:45:35 pilots vtltape[10967]: processMessageQ: Library requested tape unload
Aug  3 09:45:38 pilots vtllibrary[11103]: CDB (17062) 00 00 00 00 00 00
Aug  3 09:45:38 pilots vtllibrary[11103]: processCommand: Test Unit Ready : Returning =>  Yes
Aug  3 09:45:38 pilots vtllibrary[11103]: completeSCSICommand: OP s/n: (17062), sz: 0, sam_status: 0
Aug  3 09:45:38 pilots xinetd[2483]: EXIT: omni status=4 pid=11384 duration=7(sec)
Aug  3 09:45:39 pilots xinetd[2483]: START: omni pid=11388 from=127.0.0.1
Aug  3 09:45:39 pilots xinetd[2483]: EXIT: omni status=0 pid=11388 duration=0(sec)



I can see that there are some kernel message in the above log:
kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
But don't know if it is related.
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Mon Aug 02, 2010 10:29 pm

Aug 3 09:45:35 pilots vtltape[10967]: CDB (17043) 11 01 00 00 03 00
Aug 3 09:45:35 pilots vtltape[10967]: processCommand: SPACE (17043) ** 3 filemarks
Aug 3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17043), sz: 0, sam_status: 0
Aug 3 09:45:35 pilots vtltape[10967]: CDB (17044) 08 00 01 00 00 00
Aug 3 09:45:35 pilots vtltape[10967]: processCommand: READ_6 (17044) : 65536 bytes **
Aug 3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17044), sz: 65536, sam_status: 0
Aug 3 09:45:35 pilots vtltape[10967]: CDB (17045) 11 00 ff ff ff 00
Aug 3 09:45:35 pilots vtltape[10967]: processCommand: SPACE (17045) ** 16777215 blocks
Aug 3 09:45:35 pilots vtltape[10967]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [80 00 01]
Aug 3 09:45:35 pilots vtltape[10967]: completeSCSICommand: OP s/n: (17045), sz: 0, sam_status: 2

OK, this looks like a bug I need to fix..

Told to position 3 filemarks - Succeed.
Read a 64k block of data - Succeed.
Skip back one filemark - Failed.

I don't know why this is failing but will look into it tomorrow.

Thanks for the bug report.

p.s. The 'convert to use sg_io' is a warning from linux kernel to advise your program is using an old ioctl() interface and should be upgraded to the new sg i/o interface. Sometime in the future, the ioctl() this program is using will be removed and hence the program will no longer function.
I assume rma is something to do with HP-Data Protector?


Cheers
Mark
Last edited by markh794 on Tue Aug 03, 2010 6:44 am, edited 1 time in total.
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby cup » Tue Aug 03, 2010 3:38 am

Right, rma is DataProtector's daemon, still using old ioctl().

Thank you !
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Thu Aug 05, 2010 7:52 am

Unfortunately, I've been unable to reproduce this error.. I'm not sure why.

Is there a chance of tar & compressing the /opt/mhvtl/DD1001L4 directory and forwarding direct to my email address ([hidden email]) so I can test against this image ?

Many thanks
Mark
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby cup » Fri Aug 06, 2010 3:36 am

For sure, just sent it out.

Thanks a lot !
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Sat Aug 07, 2010 6:35 am

Received.

Thanks.

I'll have a look at it this coming week.
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Tue Aug 10, 2010 7:32 pm

I've found what it occurring.
I'm going to confirm against a real tape drive today to observe the behaviour (although I'm certain I'm wrong).

Write x data blocks
Write 2 filemarks
Write 1 data block
Write 1 filemark

Now rewind.
seek 2 filemarks forward. - Good
read 64k block of data - Good
Seek backwards one data block (although why TSM wants to rewind the block it just read is unknown)
Oops: Here is where the mhvtl code is throwing a 'found filemark' which is throwing TSM into a fault condition.

FWIW: A 'seek backwareds one filemark' works just fine.

I'm working on a fix.

p.s. Many thanks for the data sent earlier.
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Fri Aug 13, 2010 6:59 am

I've uploaded a new image to test.
https://sites.google.com/site/linuxvtl2 ... ects=0&d=1

Any chance of having somebody with TSM test I've done the right thing.
I need to test against NetBackup tomorow.

If this works OK with TSM and NetBackup, it will be the 0.18-10 release.

Cheers
Mark
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby nia » Sat Aug 14, 2010 1:16 am

Although this post is about HP DataProtector 6.11 but I am currently testing this with TSM anyway, however It will be few days before I can tell if this is fixed some similar TSM issue I was having ..
~nia
nia
Forum Founder
 
Posts: 273
Joined: Sat Dec 12, 2009 12:51 pm
Location: USA

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Sat Aug 14, 2010 1:44 am

Just to confirm I've run this build (2010-08-14) against NetBackup 7.0.1FA (First Availability) without error.
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby nia » Sun Aug 15, 2010 4:23 am

Seems to have fixed my TSM OP=FSR -- (forward space record) error .. :)
~nia
nia
Forum Founder
 
Posts: 273
Joined: Sat Dec 12, 2009 12:51 pm
Location: USA

Re: MHVTL with HP DataProtector 6.11

Postby cup » Sun Aug 15, 2010 10:11 pm

Hi, tried again in Data Protector, failed again in a second backup on the same tape, first backup is successful on a new tape. This is a very simple full backup for just one file.

dump_tape output:
CODE: SELECT ALL
PCL is : DD1002L4
Media density code: 0x46
Media type code   : 0x08
Media description : Ultrium 4/8T
Tape Capacity     : 21474836480
Hdr:             data(0b), sz   8192/8192  , Blk No.: 0, data 0
Hdr:             data(0b), sz  65536/65536 , Blk No.: 1, data 8192
Hdr:         Filemark(03), sz             0, Blk No.: 2, data 73728
Hdr:             data(0b), sz  65536/65536 , Blk No.: 3, data 73728
Hdr:         Filemark(03), sz             0, Blk No.: 4, data 139264
Hdr:             data(0b), sz  65536/65536 , Blk No.: 5, data 139264
Hdr:         Filemark(03), sz             0, Blk No.: 6, data 204800
Hdr:         Filemark(03), sz             0, Blk No.: 7, data 204800
Hdr:      End of Data(05), sz             0, Blk No.: 8, data 204800



log messages:
CODE: SELECT ALL
Aug 16 10:06:33 pilots xinetd[2483]: START: omni pid=3982 from=127.0.0.1
Aug 16 10:06:33 pilots xinetd[2483]: EXIT: omni status=0 pid=3982 duration=0(sec)
Aug 16 10:06:34 pilots xinetd[2483]: START: omni pid=3983 from=127.0.0.1
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (497) 12 00 00 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (497), sz: 66, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (498) 12 01 80 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:34 pilots vtllibrary[3718]: spc_inquiry: Page code 0x80
Aug 16 10:06:34 pilots vtllibrary[3718]: spc_inquiry: Found page 0x80
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (498), sz: 14, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (499) 12 00 00 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (499), sz: 66, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (500) 1a 00 1d 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: MODE SENSE **
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Mode Sense 6 byte version
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Page Code     : 0x1d
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Disable Block Descriptor => No
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Allocation len: 255
Aug 16 10:06:34 pilots vtllibrary[3718]: find_pcode: (0x1d): match pcode 29
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (500), sz: 32, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (501) 12 00 00 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (501), sz: 66, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (502) 00 00 00 00 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (502), sz: 0, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (503) 1a 00 1d 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: MODE SENSE **
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Mode Sense 6 byte version
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Page Code     : 0x1d
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Disable Block Descriptor => No
Aug 16 10:06:34 pilots vtllibrary[3718]: resp_mode_sense:  Allocation len: 255
Aug 16 10:06:34 pilots vtllibrary[3718]: find_pcode: (0x1d): match pcode 29
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (503), sz: 32, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (504) b8 14 00 01 00 01 00 00 00 ff 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 04 80 00 34 00 00 00 34
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_page: Slot: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: slot2struct: slot2struct: Drive 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 0, VOLTAG: 1, Index: 12
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 3c
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (504), sz: 68, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (505) b8 04 00 01 00 01 01 00 00 ff 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 32 00 00 00 32
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_page: Slot: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: slot2struct: slot2struct: Drive 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 1, VOLTAG: 0, Index: 12
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 3a
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (505), sz: 66, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (506) 00 00 00 00 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (506), sz: 0, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (507) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_page: Slot: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: slot2struct: slot2struct: Drive 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (507), sz: 32, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (508) b8 02 04 01 00 01 00 00 00 ff 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_page: Slot: 1025
Aug 16 10:06:34 pilots vtllibrary[3718]: slot2struct: slot2struct: Storage 1025
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1025
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1025, number of configured slots: 1
Aug 16 10:06:34 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 01 00 01 00 00 00 18
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (508), sz: 32, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (509) 12 00 00 00 ff 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (509), sz: 66, sam_status: 0
Aug 16 10:06:34 pilots vtllibrary[3718]: CDB (510) a5 00 00 00 04 01 00 01 00 00 00 00
Aug 16 10:06:34 pilots vtllibrary[3718]: processCommand: MOVE MEDIUM **
Aug 16 10:06:34 pilots vtllibrary[3718]: Moving from slot 1025 to Slot 1 using transport 0, Invert media: no
Aug 16 10:06:34 pilots vtllibrary[3718]: slot2struct: slot2struct: Storage 1025
Aug 16 10:06:34 pilots vtllibrary[3718]: move_slot2drive: About to send cmd: 'lload DD1002L4' to drive 11
Aug 16 10:06:34 pilots vtltape[3570]: processMessageQ: Q snd_id 10 msg : lload DD1002L4
Aug 16 10:06:34 pilots vtltape[3570]: load_tape: Opening file/media /opt/mhvtl/DD1002L4
Aug 16 10:06:34 pilots vtltape[3570]: loadTape: MAM: media S/No. DD1002L4_1281923920
Aug 16 10:06:34 pilots vtltape[3570]: find_pcode: (0x1d): match pcode 29
Aug 16 10:06:34 pilots vtltape[3570]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [06 28 00]
Aug 16 10:06:34 pilots vtltape[3570]: loadTape: Tape capacity: 21474836480
Aug 16 10:06:34 pilots vtltape[3570]: updateMAM: updateMAM(1)
Aug 16 10:06:34 pilots vtltape[3570]: loadTape: Supported media list is empty, loading media
Aug 16 10:06:34 pilots vtltape[3570]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:34 pilots vtltape[3570]: loadTape: Media is writable
Aug 16 10:06:34 pilots vtltape[3570]: loadTape: Setting MediumDensityCode to 0x46
Aug 16 10:06:34 pilots vtltape[3570]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:34 pilots vtllibrary[3718]: check_tape_load: Received "Loaded OK: DD1002L4 " from message Q
Aug 16 10:06:34 pilots vtllibrary[3718]: is_map_slot: slot type 4
Aug 16 10:06:34 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (510), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (511) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Test Unit Ready (511) : Yes
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (511), sz: 0, sam_status: 2
Aug 16 10:06:38 pilots vtltape[3570]: CDB (512) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Test Unit Ready (512) : Yes
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (512), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (513) 05 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Read block limits (513) **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (513), sz: 6, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (514) 1a 00 00 00 0c 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: MODE SENSE (514) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Mode Sense 6 byte version
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Page Code     : 0x0
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Disable Block Descriptor => No
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Allocation len: 12
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (514), sz: 12, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (515) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: INQUIRY (515) **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (515), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (516) 12 01 80 00 ff 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: INQUIRY (516) **
Aug 16 10:06:38 pilots vtltape[3570]: spc_inquiry: Page code 0x80
Aug 16 10:06:38 pilots vtltape[3570]: spc_inquiry: Found page 0x80
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (516), sz: 14, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (517) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Test Unit Ready (517) : Yes
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (517), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (518) 05 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Read block limits (518) **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (518), sz: 6, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (519) 1a 00 00 00 0c 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: MODE SENSE (519) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Mode Sense 6 byte version
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Page Code     : 0x0
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Disable Block Descriptor => No
Aug 16 10:06:38 pilots vtltape[3570]: resp_mode_sense:  Allocation len: 12
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (519), sz: 12, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (520) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: INQUIRY (520) **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (520), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (521) 01 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Rewinding (521) **
Aug 16 10:06:38 pilots vtltape[3570]: rewind_tape: Media is writable
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (521), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (522) a2 20 00 10 00 00 00 00 00 ff 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Security Protocol In (522) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: Data Encryption Capabilities page
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: Drive type: 4, Media type: 8
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: LTO4 drive
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: LTO4 Medium
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (522), sz: 44, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (523) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Security Protocol In (523) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: Data Encryption Status page
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (523), sz: 24, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (524) 08 00 00 20 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: READ_6 (524) : 8192 bytes **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (524), sz: 8192, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (525) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: INQUIRY (525) **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (525), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (526) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: LOG SENSE (526) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 16 10:06:38 pilots vtltape[3570]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (526), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (527) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (527), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (528) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (528), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (529) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: LOG SENSE **
Aug 16 10:06:38 pilots vtllibrary[3718]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtllibrary[3718]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (529), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (530) 11 01 0f 42 40 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: SPACE (530) ** forward 1000000 filemarks
Aug 16 10:06:38 pilots vtltape[3570]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [08 00 05]
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (530), sz: 0, sam_status: 2
Aug 16 10:06:38 pilots xinetd[2483]: START: omni pid=3986 from=127.0.0.1
Aug 16 10:06:38 pilots vtltape[3570]: CDB (531) 11 01 ff ff fe 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: SPACE (531) ** back 2 filemarks
Aug 16 10:06:38 pilots vtltape[3570]: position_to_block: Position to block 6
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (531), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (532) 11 00 ff ff ff 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: SPACE (532) ** back 1 block
Aug 16 10:06:38 pilots vtltape[3570]: position_to_block: Position to block 6
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (532), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (533) 08 00 01 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: READ_6 (533) : 65536 bytes **
Aug 16 10:06:38 pilots vtltape[3570]: readBlock: Expected to find hdr type: 11, found: 3
Aug 16 10:06:38 pilots vtltape[3570]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [80 00 01]
Aug 16 10:06:38 pilots vtltape[3570]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [20 00 00]
Aug 16 10:06:38 pilots vtltape[3570]: mk_sense_short_block: Short block read: Requested: 65536, Read: 0, short by 65536 bytes
Aug 16 10:06:38 pilots vtltape[3570]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [80 00 01]
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (533), sz: 0, sam_status: 2
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (534) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: LOG SENSE (534) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 16 10:06:38 pilots vtltape[3570]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (534), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (535) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (535), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (536) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (536), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (537) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: LOG SENSE **
Aug 16 10:06:38 pilots vtllibrary[3718]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtllibrary[3718]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (537), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (538) 01 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Rewinding (538) **
Aug 16 10:06:38 pilots vtltape[3570]: rewind_tape: Media is writable
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (538), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (539) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: LOG SENSE (539) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtltape[3570]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 16 10:06:38 pilots vtltape[3570]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (539), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (540) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (540), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (541) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (541), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (542) 4d 00 2e 00 00 00 00 01 44 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: LOG SENSE **
Aug 16 10:06:38 pilots vtllibrary[3718]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 16 10:06:38 pilots vtllibrary[3718]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (542), sz: 324, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (543) 08 00 00 20 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: READ_6 (543) : 8192 bytes **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (543), sz: 8192, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (544) 01 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Rewinding (544) **
Aug 16 10:06:38 pilots vtltape[3570]: rewind_tape: Media is writable
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (544), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots kernel: program bma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 16 10:06:38 pilots vtltape[3570]: CDB (545) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Security Protocol In (545) **
Aug 16 10:06:38 pilots vtltape[3570]: resp_spin_page_20: Data Encryption Status page
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (545), sz: 24, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: CDB (546) 1b 00 00 00 00 00
Aug 16 10:06:38 pilots vtltape[3570]: updateMAM: updateMAM(0)
Aug 16 10:06:38 pilots vtltape[3570]: find_pcode: (0x1d): match pcode 29
Aug 16 10:06:38 pilots vtltape[3570]: clearWORM: WORM mode page cleared
Aug 16 10:06:38 pilots vtltape[3570]: processCommand: Unloading Tape (546)  **
Aug 16 10:06:38 pilots vtltape[3570]: completeSCSICommand: OP s/n: (546), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (547) 00 00 00 00 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (547), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (548) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_page: Slot: 1
Aug 16 10:06:38 pilots vtllibrary[3718]: slot2struct: slot2struct: Drive 1
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (548), sz: 32, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (549) b8 02 04 01 00 01 00 00 00 ff 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: READ ELEMENT STATUS **
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_page: Slot: 1025
Aug 16 10:06:38 pilots vtllibrary[3718]: slot2struct: slot2struct: Storage 1025
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_descriptor: Slot location: 1025
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Starting slot: 1025, number of configured slots: 1
Aug 16 10:06:38 pilots vtllibrary[3718]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 01 00 01 00 00 00 18
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (549), sz: 32, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (550) 12 00 00 00 ff 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: INQUIRY **
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (550), sz: 66, sam_status: 0
Aug 16 10:06:38 pilots vtllibrary[3718]: CDB (551) a5 00 00 00 00 01 04 01 00 00 00 00
Aug 16 10:06:38 pilots vtllibrary[3718]: processCommand: MOVE MEDIUM **
Aug 16 10:06:38 pilots vtllibrary[3718]: Moving from slot 1 to Slot 1025 using transport 0, Invert media: no
Aug 16 10:06:38 pilots vtllibrary[3718]: slot2struct: slot2struct: Storage 1025
Aug 16 10:06:38 pilots vtllibrary[3718]: is_map_slot: slot type 2
Aug 16 10:06:38 pilots vtllibrary[3718]: is_map_slot: slot type 2
Aug 16 10:06:38 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (551), sz: 0, sam_status: 0
Aug 16 10:06:38 pilots vtltape[3570]: processMessageQ: Q snd_id 10 msg : unload
Aug 16 10:06:38 pilots vtltape[3570]: unloadTape: Tape not mounted
Aug 16 10:06:38 pilots vtltape[3570]: processMessageQ: Library requested tape unload
Aug 16 10:06:39 pilots xinetd[2483]: EXIT: omni status=4 pid=3986 duration=1(sec)
Aug 16 10:06:41 pilots vtllibrary[3718]: CDB (552) 00 00 00 00 00 00
Aug 16 10:06:41 pilots vtllibrary[3718]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 16 10:06:41 pilots vtllibrary[3718]: completeSCSICommand: OP s/n: (552), sz: 0, sam_status: 0
Aug 16 10:06:41 pilots xinetd[2483]: EXIT: omni status=4 pid=3983 duration=7(sec)
Aug 16 10:06:42 pilots xinetd[2483]: START: omni pid=3992 from=127.0.0.1
Aug 16 10:06:42 pilots xinetd[2483]: EXIT: omni status=0 pid=3992 duration=0(sec)
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby markh794 » Mon Aug 16, 2010 7:32 am

Thanks for the report & testing..

I'll have another stab at it tomorrow :)

The 'pattern' is slightly different this time.

Cheers
Mark
markh794
MHVTL - Developer
 
Posts: 101
Joined: Sat Feb 20, 2010 6:30 pm
Location: Sydney, Australia

Re: MHVTL with HP DataProtector 6.11

Postby cup » Mon Aug 16, 2010 10:59 pm

Hi, thanks a lot.

Using the 08-17 source, this time backup is fine, performed 2 backups using the same tape successfully, but when tried to restore the 2nd image, error founded. Data Protector will mark this tape as bad.

messages:
CODE: SELECT ALL
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (420) 12 00 00 00 ff 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (420), sz: 66, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (421) 1a 00 1d 00 ff 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: MODE SENSE **
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Mode Sense 6 byte version
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Page Code     : 0x1d
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Disable Block Descriptor => No
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Allocation len: 255
Aug 17 10:51:56 pilots vtllibrary[8736]: find_pcode: (0x1d): match pcode 29
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (421), sz: 32, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (422) 12 00 00 00 ff 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (422), sz: 66, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (423) 00 00 00 00 00 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (423), sz: 0, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (424) 1a 00 1d 00 ff 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: MODE SENSE **
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Mode Sense 6 byte version
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Page Code     : 0x1d
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Disable Block Descriptor => No
Aug 17 10:51:56 pilots vtllibrary[8736]: resp_mode_sense:  Allocation len: 255
Aug 17 10:51:56 pilots vtllibrary[8736]: find_pcode: (0x1d): match pcode 29
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (424), sz: 32, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (425) 00 00 00 00 00 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (425), sz: 0, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (426) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: READ ELEMENT STATUS **
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_page: Slot: 1
Aug 17 10:51:56 pilots vtllibrary[8736]: slot2struct: slot2struct: Drive 1
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_descriptor: Slot location: 1
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (426), sz: 32, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (427) b8 02 04 00 00 01 00 00 00 ff 00 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: READ ELEMENT STATUS **
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_page: Slot: 1024
Aug 17 10:51:56 pilots vtllibrary[8736]: slot2struct: slot2struct: Storage 1024
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_descriptor: Slot location: 1024
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Starting slot: 1024, number of configured slots: 1
Aug 17 10:51:56 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 00 00 01 00 00 00 18
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (427), sz: 32, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (428) 12 00 00 00 ff 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:51:56 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (428), sz: 66, sam_status: 0
Aug 17 10:51:56 pilots vtllibrary[8736]: CDB (429) a5 00 00 00 04 00 00 01 00 00 00 00
Aug 17 10:51:56 pilots vtllibrary[8736]: processCommand: MOVE MEDIUM **
Aug 17 10:51:56 pilots vtllibrary[8736]: Moving from slot 1024 to Slot 1 using transport 0, Invert media: no
Aug 17 10:51:56 pilots vtllibrary[8736]: slot2struct: slot2struct: Storage 1024
Aug 17 10:51:56 pilots vtllibrary[8736]: move_slot2drive: About to send cmd: 'lload DD1001L4' to drive 11
Aug 17 10:51:57 pilots vtltape[8695]: processMessageQ: Q snd_id 10 msg : lload DD1001L4
Aug 17 10:51:57 pilots vtltape[8695]: load_tape: Opening file/media /opt/mhvtl/DD1001L4
Aug 17 10:51:57 pilots vtltape[8695]: loadTape: MAM: media S/No. DD1001L4_1282013182
Aug 17 10:51:57 pilots vtltape[8695]: find_pcode: (0x1d): match pcode 29
Aug 17 10:51:57 pilots vtltape[8695]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [06 28 00]
Aug 17 10:51:57 pilots vtltape[8695]: loadTape: Tape capacity: 21474836480
Aug 17 10:51:57 pilots vtltape[8695]: updateMAM: updateMAM(1)
Aug 17 10:51:57 pilots vtltape[8695]: loadTape: Supported media list is empty, loading media
Aug 17 10:51:57 pilots vtltape[8695]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:51:57 pilots vtltape[8695]: loadTape: Media is writable
Aug 17 10:51:57 pilots vtltape[8695]: loadTape: Setting MediumDensityCode to 0x46
Aug 17 10:51:57 pilots vtltape[8695]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:51:57 pilots vtllibrary[8736]: check_tape_load: Received "Loaded OK: DD1001L4 " from message Q
Aug 17 10:51:57 pilots vtllibrary[8736]: is_map_slot: slot type 4
Aug 17 10:51:57 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (429), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (430) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Test Unit Ready (430) : Yes
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (430), sz: 0, sam_status: 2
Aug 17 10:52:00 pilots vtltape[8695]: CDB (431) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Test Unit Ready (431) : Yes
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (431), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (432) 05 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Read block limits (432) **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (432), sz: 6, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (433) 1a 00 00 00 0c 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: MODE SENSE (433) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Mode Sense 6 byte version
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Page Code     : 0x0
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Disable Block Descriptor => No
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Allocation len: 12
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (433), sz: 12, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (434) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Test Unit Ready (434) : Yes
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (434), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (435) 05 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Read block limits (435) **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (435), sz: 6, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (436) 1a 00 00 00 0c 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: MODE SENSE (436) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Mode Sense 6 byte version
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Page Control  : Current configuration(0x0)
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Page Code     : 0x0
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Disable Block Descriptor => No
Aug 17 10:52:00 pilots vtltape[8695]: resp_mode_sense:  Allocation len: 12
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (436), sz: 12, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (437) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: INQUIRY (437) **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (437), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (438) 01 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Rewinding (438) **
Aug 17 10:52:00 pilots vtltape[8695]: rewind_tape: Media is writable
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (438), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (439) a2 20 00 10 00 00 00 00 00 ff 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Security Protocol In (439) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: Data Encryption Capabilities page
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: Drive type: 4, Media type: 8
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: LTO4 drive
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: LTO4 Medium
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (439), sz: 44, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (440) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Security Protocol In (440) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: Data Encryption Status page
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (440), sz: 24, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (441) 08 00 00 20 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: READ_6 (441) : 8192 bytes **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (441), sz: 8192, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (442) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: INQUIRY (442) **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (442), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (443) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: LOG SENSE (443) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 17 10:52:00 pilots vtltape[8695]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (443), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (444) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (444), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (445) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (445), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (446) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: LOG SENSE **
Aug 17 10:52:00 pilots vtllibrary[8736]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtllibrary[8736]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (446), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (447) 11 01 00 00 03 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: SPACE (447) ** forward 3 filemarks
Aug 17 10:52:00 pilots vtltape[8695]: position_to_block: Position to block 7
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (447), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (448) 08 00 01 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: READ_6 (448) : 65536 bytes **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (448), sz: 65536, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (449) 11 00 ff ff ff 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: SPACE (449) ** back 1 block
Aug 17 10:52:00 pilots vtltape[8695]: mkSenseBuf: SENSE [Key/ASC/ASCQ] [80 00 01]
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (449), sz: 0, sam_status: 2
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (450) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: LOG SENSE (450) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 17 10:52:00 pilots vtltape[8695]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (450), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (451) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (451), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (452) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (452), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (453) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: LOG SENSE **
Aug 17 10:52:00 pilots vtllibrary[8736]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtllibrary[8736]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (453), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (454) 01 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Rewinding (454) **
Aug 17 10:52:00 pilots vtltape[8695]: rewind_tape: Media is writable
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (454), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (455) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: LOG SENSE (455) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtltape[8695]: resp_log_sense:  Returning TapeAlert flags: 0x0
Aug 17 10:52:00 pilots vtltape[8695]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (455), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (456) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (456), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (457) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (457), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (458) 4d 00 2e 00 00 00 00 01 44 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: LOG SENSE **
Aug 17 10:52:00 pilots vtllibrary[8736]: resp_log_sense: LOG SENSE: TapeAlert page
Aug 17 10:52:00 pilots vtllibrary[8736]: setTapeAlert: Setting TapeAlert flags 0x00000000 00000000
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (458), sz: 324, sam_status: 0
Aug 17 10:52:00 pilots kernel: program rma is using a deprecated SCSI ioctl, please convert it to SG_IO
Aug 17 10:52:00 pilots vtltape[8695]: CDB (459) a2 20 00 20 00 00 00 00 00 ff 00 00
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Security Protocol In (459) **
Aug 17 10:52:00 pilots vtltape[8695]: resp_spin_page_20: Data Encryption Status page
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (459), sz: 24, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: CDB (460) 1b 00 00 00 00 00
Aug 17 10:52:00 pilots vtltape[8695]: updateMAM: updateMAM(0)
Aug 17 10:52:00 pilots vtltape[8695]: find_pcode: (0x1d): match pcode 29
Aug 17 10:52:00 pilots vtltape[8695]: clearWORM: WORM mode page cleared
Aug 17 10:52:00 pilots vtltape[8695]: processCommand: Unloading Tape (460)  **
Aug 17 10:52:00 pilots vtltape[8695]: completeSCSICommand: OP s/n: (460), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (461) 00 00 00 00 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (461), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (462) b8 04 00 01 00 01 00 00 00 ff 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: READ ELEMENT STATUS **
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_page_hdr: Element Status Page Header: 04 00 00 10 00 00 00 10
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_page: Slot: 1
Aug 17 10:52:00 pilots vtllibrary[8736]: slot2struct: slot2struct: Drive 1
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_descriptor: Slot location: 1
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Starting slot: 1, number of configured slots: 1
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Element Status Data HEADER: 00 01 00 01 00 00 00 18
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (462), sz: 32, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (463) b8 02 04 00 00 01 00 00 00 ff 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: READ ELEMENT STATUS **
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_page_hdr: Element Status Page Header: 02 00 00 10 00 00 00 10
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_page: Slot: 1024
Aug 17 10:52:00 pilots vtllibrary[8736]: slot2struct: slot2struct: Storage 1024
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_descriptor: Slot location: 1024
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_descriptor: DVCID: 0, VOLTAG: 0, Index: 12
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr: Building READ ELEMENT STATUS Header struct
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Starting slot: 1024, number of configured slots: 1
Aug 17 10:52:00 pilots vtllibrary[8736]: fill_element_status_data_hdr:  Element Status Data HEADER: 04 00 00 01 00 00 00 18
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (463), sz: 32, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (464) 12 00 00 00 ff 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: INQUIRY **
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (464), sz: 66, sam_status: 0
Aug 17 10:52:00 pilots vtllibrary[8736]: CDB (465) a5 00 00 00 00 01 04 00 00 00 00 00
Aug 17 10:52:00 pilots vtllibrary[8736]: processCommand: MOVE MEDIUM **
Aug 17 10:52:00 pilots vtllibrary[8736]: Moving from slot 1 to Slot 1024 using transport 0, Invert media: no
Aug 17 10:52:00 pilots vtllibrary[8736]: slot2struct: slot2struct: Storage 1024
Aug 17 10:52:00 pilots vtllibrary[8736]: is_map_slot: slot type 2
Aug 17 10:52:00 pilots vtllibrary[8736]: is_map_slot: slot type 2
Aug 17 10:52:00 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (465), sz: 0, sam_status: 0
Aug 17 10:52:00 pilots vtltape[8695]: processMessageQ: Q snd_id 10 msg : unload
Aug 17 10:52:00 pilots vtltape[8695]: unloadTape: Tape not mounted
Aug 17 10:52:00 pilots vtltape[8695]: processMessageQ: Library requested tape unload
Aug 17 10:52:03 pilots vtllibrary[8736]: CDB (466) 00 00 00 00 00 00
Aug 17 10:52:03 pilots vtllibrary[8736]: processCommand: Test Unit Ready : Returning =>  Yes
Aug 17 10:52:03 pilots vtllibrary[8736]: completeSCSICommand: OP s/n: (466), sz: 0, sam_status: 0
Aug 17 10:52:03 pilots xinetd[2483]: EXIT: omni status=4 pid=9057 duration=7(sec)
Aug 17 10:52:04 pilots xinetd[2483]: START: omni pid=9061 from=127.0.0.1
Aug 17 10:52:04 pilots xinetd[2483]: EXIT: omni status=0 pid=9061 duration=0(sec)


dump_tape output:
CODE: SELECT ALL
PCL is : DD1001L4
Media density code: 0x46
Media type code   : 0x08
Media description : Ultrium 4/8T
Tape Capacity     : 21474836480
Hdr:             data(0b), sz   8192/8192  , Blk No.: 0, data 0
Hdr:             data(0b), sz  65536/65536 , Blk No.: 1, data 8192
Hdr:         Filemark(03), sz             0, Blk No.: 2, data 73728
Hdr:             data(0b), sz  65536/65536 , Blk No.: 3, data 73728
Hdr:         Filemark(03), sz             0, Blk No.: 4, data 139264
Hdr:             data(0b), sz  65536/65536 , Blk No.: 5, data 139264
Hdr:         Filemark(03), sz             0, Blk No.: 6, data 204800
Hdr:             data(0b), sz  65536/65536 , Blk No.: 7, data 204800
Hdr:         Filemark(03), sz             0, Blk No.: 8, data 270336
Hdr:             data(0b), sz  65536/65536 , Blk No.: 9, data 270336
Hdr:         Filemark(03), sz             0, Blk No.: 10, data 335872
Hdr:         Filemark(03), sz             0, Blk No.: 11, data 335872
Hdr:      End of Data(05), sz             0, Blk No.: 12, data 335872
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am

Re: MHVTL with HP DataProtector 6.11

Postby cup » Sun Sep 26, 2010 10:29 pm

Hi, using 2010-09-23 version, backup and restore run successfully in Data Protector 6.11.
Also tried to emulate HP tape library with success too.

Thanks.

Part of the device.conf:
Library: 10 CHANNEL: 00 TARGET: 00 LUN: 00
Vendor identification: HP
Product identification: MSL6060 Series
Product revision level: 0520
Unit serial number: XYZZY_A
NAA: 10:22:33:44:ab:00:00:00

Drive: 11 CHANNEL: 00 TARGET: 01 LUN: 00
Library ID: 10 Slot: 01
Vendor identification: HP
Product identification: Ultrium 4-SCSI
Product revision level: B34W
Unit serial number: XYZZY_A1
NAA: 10:22:33:44:ab:00:01:00
Compression: factor 1 enabled 1

Drive: 12 CHANNEL: 00 TARGET: 02 LUN: 00
cup
Registered
 
Posts: 8
Joined: Thu Feb 18, 2010 3:59 am