Quantcast

Using LTO4 WORM media

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

Using LTO4 WORM media

Tiger22
I am trying to conduct some testing in TSM using LTO WORM media and I am struggling to understand how to correctly define LTO4 WORM media in mhVTL.

My understanding is that make_vtl_media will generate the media based upon the label name. Looking at the make_vtl_media script it will only generate WORM media if the tape label starts with a "W". Does this apply to LTO WORM media?

I wanted to create labels with the LU suffix (indicating LTO4 WORM) but do I have to still have a W label prefix? Which is correct (if either) to get the correct media created:

WA0001LU
or
AA0001LU ?

And before I delve too much further into this - Is there presently support for LTO WORM media when used by the 3573-TL library? Does the library correctly report the media type?
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
Tiger22 wrote
I am trying to conduct some testing in TSM using LTO WORM media and I am struggling to understand how to correctly define LTO4 WORM media in mhVTL.
Cool.. I've played with this in NetBackup 5.1 (about 6years old).. Hopefully the functionality works correctly - note to self, recheck WORM & NetBackup.

Tiger22 wrote
My understanding is that make_vtl_media will generate the media based upon the label name. Looking at the make_vtl_media script it will only generate WORM media if the tape label starts with a "W". Does this apply to LTO WORM media?

I wanted to create labels with the LU suffix (indicating LTO4 WORM) but do I have to still have a W label prefix? Which is correct (if either) to get the correct media created:
I need to double-check the scripts. The latest should be good with just the suffix. Earlier releases did not do the right thing.

WA0001LU
or
AA0001LU ?

Tiger22 wrote
And before I delve too much further into this - Is there presently support for LTO WORM media when used by the 3573-TL library? Does the library correctly report the media type?
Now there is a really good question..
Let me check. It may be a day or so before I am able to get back to you on this one.
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Tiger22
Hi Mark,

I've been delving a bit further. It looks like the make_vtl_media doesn't correctly handle LTO WORM generation. E.g. a WW1000LU label is being identified as an "UNKNOWN media type" when loading into an LTO-4 drive. The density appears to be correctly set but the LTO WORM suffix identification logic is not also present in the media_type() function. I can probably work on updating that if you like.

Anyway, that aside, I manually created a tape using the mktape utility as follows:

mktape -l 20 -m WW0001LU -s 2048 -t WORM -d LTO4

I then tried to label that tape in TSM but I am getting a TSM error saying it could not write the label. The vtl logging suggests an End of Medium message is being returned when the block is attempted to be written. I include below various logs and configuration information to see if you know what might be going on.

TSM Activity Log:

03/19/2015 10:39:12      ANR0407I Session 2 started for administrator ADMIN (Linux
                          x86-64) (Tcp/Ip dbtsm1.pts.co.uk(48798)). (SESSION: 2)
03/19/2015 10:39:13      ANR2017I Administrator ADMIN issued command: LABEL
                          LIBVOLUME ts3200 search=yes checkin=scratch
                          labels=barcode  (SESSION: 2)
03/19/2015 10:39:13      ANR0984I Process 2 for LABEL LIBVOLUME started in the
                          BACKGROUND at 10:39:13 AM. (SESSION: 2, PROCESS: 2)
03/19/2015 10:39:13      ANR8799I LABEL LIBVOLUME: Operation for library TS3200
                          started as process 2. (SESSION: 2, PROCESS: 2)
03/19/2015 10:39:15      ANR8806E Could not write volume label WW0001LU on the tape
                          in library TS3200. (SESSION: 2, PROCESS: 2)
03/19/2015 10:39:15      ANR8802E LABEL LIBVOLUME process 2 for library TS3200
                          failed. (SESSION: 2, PROCESS: 2)
03/19/2015 10:39:15      ANR0985I Process 2 for LABEL LIBVOLUME running in the
                          BACKGROUND completed with completion state FAILURE at
                          10:39:15 AM. (SESSION: 2, PROCESS: 2)
03/19/2015 10:39:15      ANR1893E Process 2 for LABEL LIBVOLUME completed with a
                          completion state of FAILURE. (SESSION: 2, PROCESS: 2)

mhVTL log output:

[root]# tail -f /var/lg/messages
Mar 19 10:38:42 dbtsm1 vtllibrary[2798]: processMessageQ(): Sender id: 32768, msg : verbose
Mar 19 10:38:42 dbtsm1 vtllibrary[2798]: processMessageQ(): verbose: disabled at level 0
Mar 19 10:38:48 dbtsm1 vtllibrary[2798]: processMessageQ(): verbose: enabled at level 3
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (470) (delay 989205): 12 00 00 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (470)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (470), sz: 72, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (471) (delay 805): 12 01 80 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (471)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (471), sz: 26, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (472) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: return_sense(): [Key/ASC/ASCQ] [06 29 00]
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): s/n: (472), sz: 0, sam_status: 2 [06 29 00]
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (473) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (473)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (473), sz: 26, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (474) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_tur(): ** TEST UNIT READY : Returning =>  (474) Online **
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (474), sz: 0, sam_status: 0
Mar 19 10:39:13 dbtsm1 kernel: lin_tape: IBMChgr1----- changer_check_result sensekey: 6 asc: 29 ascq: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (475) (delay 405): 12 00 00 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (475)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (475), sz: 72, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (476) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (476)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x80
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (476), sz: 26, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (477) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (477)
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x83
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x83
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (477), sz: 54, sam_status: 0
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: CDB (478) (delay 405): 07 00 00 00 00 00
Mar 19 10:39:13 dbtsm1 vtllibrary[2798]: smc_initialize_element_status(): INITIALIZE ELEMENT (478) **
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (478), sz: 0, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (479) (delay 1205): 12 00 00 00 ff 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (479)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (479), sz: 72, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (480) (delay 805): 12 01 80 00 ff 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (480)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x80
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x80
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (480), sz: 26, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (481) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_tur(): ** TEST UNIT READY : Returning =>  (481) Online **
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (481), sz: 0, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (482) (delay 805): 12 00 00 00 ff 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (482)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (482), sz: 72, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (483) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (483)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x80
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x80
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (483), sz: 26, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (484) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): INQUIRY ** (484)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Page code 0x83
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_inquiry(): Found page 0x83
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (484), sz: 54, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (485) (delay 805): 1a 08 1d 00 18 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_mode_sense(): MODE SENSE 6 (485) **
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_mode_sense():  Page Control     : Current values(0x00)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_mode_sense():  Page/Subpage Code: 0x1d/0x00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_mode_sense():  Disable Block Descriptor
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: spc_mode_sense():  Allocation len   : 24
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: lookup_pcode(): Looking for: Page/subpage (1d/00)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: lookup_pcode(): Found "Element Address" -> Page/subpage (1d/00)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: completeSCSICommand(): OP s/n: (485), sz: 24, sam_status: 0
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: CDB (486) (delay 405): b8 12 10 00 00 27 00 00 07 fc 00 00
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status(): READ ELEMENT STATUS (486) **
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status():  Element type(2) => Storage
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status():   Starting Element Address: 4096
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status():   Number of Elements      : 39
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status():   Allocation length       : 2044 (0x07fc)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: smc_read_element_status():   Device ID: No, voltag: Yes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Query 39 elements starting from addr: 4096 of type: (2) Storage
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: num_available_elements(): Determining 39 elements of type Storage starting at 4096, returning 39
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Available count: 39, type: (2) Storage
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_status_page_hdr(): Element Status Page Header: 02 80 00 34 00 00 07 ec
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4096, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 1, max_count: 39, slot: 4096, byte_count: 0x003c (60)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4097, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 2, max_count: 39, slot: 4097, byte_count: 0x0070 (112)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4098, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 3, max_count: 39, slot: 4098, byte_count: 0x00a4 (164)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4099, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 4, max_count: 39, slot: 4099, byte_count: 0x00d8 (216)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4100, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 5, max_count: 39, slot: 4100, byte_count: 0x010c (268)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4101, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 6, max_count: 39, slot: 4101, byte_count: 0x0140 (320)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4102, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 7, max_count: 39, slot: 4102, byte_count: 0x0174 (372)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4103, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 8, max_count: 39, slot: 4103, byte_count: 0x01a8 (424)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4104, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 9, max_count: 39, slot: 4104, byte_count: 0x01dc (476)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4105, DVCID: 0, VOLTAG: 1, status: 0x09
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 10, max_count: 39, slot: 4105, byte_count: 0x0210 (528)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4106, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 11, max_count: 39, slot: 4106, byte_count: 0x0244 (580)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4107, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 12, max_count: 39, slot: 4107, byte_count: 0x0278 (632)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4108, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 13, max_count: 39, slot: 4108, byte_count: 0x02ac (684)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4109, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 14, max_count: 39, slot: 4109, byte_count: 0x02e0 (736)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4110, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 15, max_count: 39, slot: 4110, byte_count: 0x0314 (788)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4111, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 16, max_count: 39, slot: 4111, byte_count: 0x0348 (840)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4112, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 17, max_count: 39, slot: 4112, byte_count: 0x037c (892)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4113, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 18, max_count: 39, slot: 4113, byte_count: 0x03b0 (944)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4114, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 19, max_count: 39, slot: 4114, byte_count: 0x03e4 (996)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4115, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 20, max_count: 39, slot: 4115, byte_count: 0x0418 (1048)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4116, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 21, max_count: 39, slot: 4116, byte_count: 0x044c (1100)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4117, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 22, max_count: 39, slot: 4117, byte_count: 0x0480 (1152)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4118, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 23, max_count: 39, slot: 4118, byte_count: 0x04b4 (1204)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4119, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 24, max_count: 39, slot: 4119, byte_count: 0x04e8 (1256)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4120, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 25, max_count: 39, slot: 4120, byte_count: 0x051c (1308)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4121, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 26, max_count: 39, slot: 4121, byte_count: 0x0550 (1360)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4122, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 27, max_count: 39, slot: 4122, byte_count: 0x0584 (1412)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4123, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 28, max_count: 39, slot: 4123, byte_count: 0x05b8 (1464)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4124, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 29, max_count: 39, slot: 4124, byte_count: 0x05ec (1516)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4125, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 30, max_count: 39, slot: 4125, byte_count: 0x0620 (1568)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4126, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 31, max_count: 39, slot: 4126, byte_count: 0x0654 (1620)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4127, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 32, max_count: 39, slot: 4127, byte_count: 0x0688 (1672)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4128, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 33, max_count: 39, slot: 4128, byte_count: 0x06bc (1724)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4129, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 34, max_count: 39, slot: 4129, byte_count: 0x06f0 (1776)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4130, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 35, max_count: 39, slot: 4130, byte_count: 0x0724 (1828)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4131, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 36, max_count: 39, slot: 4131, byte_count: 0x0758 (1880)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4132, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 37, max_count: 39, slot: 4132, byte_count: 0x078c (1932)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4133, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 38, max_count: 39, slot: 4133, byte_count: 0x07c0 (1984)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Slot location: 4134, DVCID: 0, VOLTAG: 1, status: 0x08
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_ed(): Returning 52 (0x34) bytes
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_page(): Count: 39, max_count: 39, slot: 4134, byte_count: 0x07f4 (2036)
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: num_available_elements(): Determining 39 elements of type Storage starting at 4096, returning 39
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_status_data_hdr(): Building READ ELEMENT STATUS Header struct
Mar 19 10:39:14 dbtsm1 vtllibrary[2798]: fill_element_status_data_hdr():  Starting slot: 4096, number of configured slots: 39
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (487) (delay 988405): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (487)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (488) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [06 29 00]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (489) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_tur(): Test Unit Ready (489) ** : No, No tape loaded
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (490) (delay 805): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (490)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (491) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_tur(): Test Unit Ready (491) ** : No, No tape loaded
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (492) (delay 805): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (492) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (493) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (493) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (494) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_in(): PERSISTENT RESERVE IN (494) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_spc_pri(): service action: 1
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (495) (delay 405): 1a 00 10 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (495) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (496) (delay 405): 15 10 00 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (496) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (497) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (497) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (498) (delay 405): 15 10 00 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (498) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: set_mode_compression():  Setting compression
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (499) (delay 405): 1a 08 10 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (499) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (500) (delay 405): 15 10 00 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (500) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (501) (delay 405): 1a 08 01 00 10 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (501) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (502) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (502) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (503) (delay 405): 05 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_block_limits(): READ BLOCK LIMITS (503) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (504) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (504) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (505) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (505) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (506) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (506) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (507) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (507)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (508) (delay 405): 12 00 00 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (508)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (509) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (509)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (510) (delay 405): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (510) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (511) (delay 405): 5f 00 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (511) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (512) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_in(): PERSISTENT RESERVE IN (512) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_spc_pri(): service action: 1
Mar 19 10:39:15 dbtsm1 vtltape[2788]: processMessageQ(): Sender id: 20, msg : lload WW0001LU
Mar 19 10:39:15 dbtsm1 vtltape[2788]: loadTape(): Media type 'LTO4' loaded with S/No. : WW0001LU_1426760262
Mar 19 10:39:15 dbtsm1 vtltape[2788]: loadTape(): Write Once Read Many (WORM) media loaded
Mar 19 10:39:15 dbtsm1 vtltape[2788]: loadTape(): Media is writable
Mar 19 10:39:15 dbtsm1 vtltape[2788]: loadTape(): Setting MediumDensityCode to LTO4 WORM (0x4c) Media type: 0x48
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (528) (delay 6005): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (528)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (529) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_tur(): Test Unit Ready (529) ** : Yes
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (530) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (530) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (531) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (531) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (532) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_in(): PERSISTENT RESERVE IN (532) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_spc_pri(): service action: 1
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (533) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (533) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (534) (delay 405): 05 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_block_limits(): READ BLOCK LIMITS (534) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (535) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (535) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (536) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (536) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (537) (delay 405): 34 00 00 00 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_position(): READ POSITION (537) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_position(): service_action: 0
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_read_position(): Positioned at block 0
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (538) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (538) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (539) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (539)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (540) (delay 805): 12 00 00 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (540)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (541) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (541)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (542) (delay 1605): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (542) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rewind_tape(): Media is writable
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (543) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (543) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (544) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (544) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (545) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (545) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (546) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (546) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (547) (delay 5): 1a 00 10 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (547) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (548) (delay 405): 15 10 00 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (548) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (549) (delay 405): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (549) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rewind_tape(): Media is writable
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (550) (delay 805): 08 02 00 00 50 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rw_6(): READ: 1 block of 80 bytes (550) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: readBlock(): Expected to find DATA header, found: EOD
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [20 00 00]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [08 00 05]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (551) (delay 805): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (551) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (552) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (552) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (553) (delay 1205): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (553) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rewind_tape(): Media is writable
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (554) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (554) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (555) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (555) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (556) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (556) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (557) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (557) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (558) (delay 5): 1a 00 10 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (558) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (559) (delay 405): 15 10 00 00 0c 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (559) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (560) (delay 405): 1a 08 0f 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (560) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (561) (delay 5): 15 10 00 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (561) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: set_mode_compression():  Clearing compression
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (562) (delay 5): 1a 08 10 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (562) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (563) (delay 405): 15 10 00 00 14 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (563) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (564) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (564) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (565) (delay 5): 0a 00 00 00 50 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rw_6(): WRITE: 1 block of 80 bytes (565) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: writeBlock(): End of Medium - VOLUME_OVERFLOW/EOM
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [4d 00 02]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (566) (delay 805): 10 00 00 00 02 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_write_filemarks(): WRITE 2 FILEMARKS (566) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (567) (delay 405): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (567) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rewind_tape(): Media is not writable
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (568) (delay 405): 5f 00 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (568) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (569) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_in(): PERSISTENT RESERVE IN (569) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_spc_pri(): service action: 1
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (570) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (570)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (571) (delay 405): 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_tur(): Test Unit Ready (571) ** : Yes
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (572) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (572) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (573) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (573) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (574) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_in(): PERSISTENT RESERVE IN (574) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_spc_pri(): service action: 1
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (575) (delay 405): 1a 00 10 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 6 (575) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (576) (delay 405): 05 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_block_limits(): READ BLOCK LIMITS (576) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (577) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (577) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (578) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (578) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (579) (delay 405): 34 00 00 00 00 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_position(): READ POSITION (579) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_read_position(): service_action: 0
Mar 19 10:39:15 dbtsm1 vtltape[2788]: resp_read_position(): Positioned at block 0
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (580) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_pr_out(): PERSISTENT RESERVE OUT (580) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (581) (delay 405): 12 01 80 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (581)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (582) (delay 405): 12 00 00 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (582)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (583) (delay 405): 12 01 83 00 ff 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_inquiry(): INQUIRY ** (583)
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (584) (delay 405): 1b 00 00 00 00 00


Library configuration (from device.conf):

Library: 20 CHANNEL: 00 TARGET: 06 LUN: 00
 Vendor identification: IBM
 Product identification: 3573-TL
 Unit serial number: 2068047945
 NAA: 10:22:33:44:ab:00:06:00
 Home directory: /opt/mhvtl
 PERSIST: False
 Backoff: 400
# fifo: /var/tmp/mhvtl

Drive: 21 CHANNEL: 01 TARGET: 07 LUN: 00
 Library ID: 20 Slot: 01
 Vendor identification: IBM
 Product identification: ULT3580-TD4
 Unit serial number: XYZZY_A5
 NAA: 10:22:33:44:ab:00:07:00
 Compression: factor 1 enabled 1
 Compression type: lzo
 Backoff: 400
# fifo: /var/tmp/mhvtl

Drive: 22 CHANNEL: 02 TARGET: 08 LUN: 00
 Library ID: 20 Slot: 02
 Vendor identification: IBM
 Product identification: ULT3580-TD4
 Unit serial number: XYZZY_A6
 NAA: 10:22:33:44:ab:00:08:00
 Compression: factor 1 enabled 1
 Compression type: lzo
 Backoff: 400
# fifo: /var/tmp/mhvtl




[root]# cat library_contents.20

Drive 1:
Drive 2:

Picker 1:

MAP 1:
MAP 2:
MAP 3:
MAP 4:

# Slot 1 - ?, no gaps
# Slot N: [barcode]
# [barcode]
# a barcode is comprised of three fields: [Leading] [identifier] [Trailing]
# Leading "CLN" -- cleaning tape
# Leading "W" -- WORM tape
# Leading "NOBAR" -- will appear to have no barcode
# If the barcode is at least 8 character long, then the last two characters are Trailing
# Trailing "S3" - SDLT600
# Trailing "X4" - AIT-4
# Trailing "L1" - LTO 1, "L2" - LTO 2, "L3" - LTO 3, "L4" - LTO 4, "L5" - LTO 5
# Trailing "LT" - LTO 3 WORM, "LU" -  LTO 4 WORM, "LV" - LTO 5 WORM
# Trailing "L6" - LTO 6, "LW" - LTO 6 WORM
# Trailing "TA" - T10000+
# Trailing "TZ" - 9840A, "TY" - 9840B, "TX" - 9840C, "TW" - 9840D
# Trailing "TV" - 9940A, "TU" - 9940B
# Trailing "JA" - 3592+
# Trailing "JB" - 3592E05+
# Trailing "JW" - WORM 3592+
# Trailing "JX" - WORM 3592E05+
# Trailing "D7" - DLT7000 media (DLT IV)
#
Slot 1:
Slot 2:
Slot 3:
Slot 4:
Slot 5:
Slot 6:
Slot 7:
Slot 8:
Slot 9:
Slot 10: TT0001LU
Slot 11:
Slot 12:
Slot 13:
Slot 14:
Slot 15:
Slot 16:
Slot 17:
Slot 18:
Slot 19:
Slot 20:
Slot 21:
Slot 22:
Slot 23:
Slot 24:
Slot 25:
Slot 26:
Slot 27:
Slot 28:
Slot 29:
Slot 30:
Slot 31:
Slot 32:
Slot 33:
Slot 34:
Slot 35:
Slot 36:
Slot 37:
Slot 38:
Slot 39:
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Tiger22
Sorry, the library contents file library_contents.20 I posted was an old, incorrect one. Slot 10 does actually contain the correct WW0001LU volume that was created using mktape:

Slot 10: WW0001LU
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
In reply to this post by Tiger22
Tiger22 wrote
Hi Mark,

I've been delving a bit further. It looks like the make_vtl_media doesn't correctly handle LTO WORM generation. E.g. a WW1000LU label is being identified as an "UNKNOWN media type" when loading into an LTO-4 drive. The density appears to be correctly set but the LTO WORM suffix identification logic is not also present in the media_type() function. I can probably work on updating that if you like.
Verified the code in vtllibrary.c is not doing the right thing. I'll look at this over the next few days. It's needed for the STK series of robots too - so some sort of call back into the library personality module needs to be implemented.

Tiger22 wrote
I then tried to label that tape in TSM but I am getting a TSM error saying it could not write the label. The vtl logging suggests an End of Medium message is being returned when the block is attempted to be written. I include below various logs and configuration information to see if you know what might be going on.
Tiger22 wrote
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select(): MODE SELECT 6 (563) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (564) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: spc_mode_sense(): MODE SENSE 10 (564) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (565) (delay 5): 0a 00 00 00 50 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rw_6(): WRITE: 1 block of 80 bytes (565) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: writeBlock(): End of Medium - VOLUME_OVERFLOW/EOM
Mar 19 10:39:15 dbtsm1 vtltape[2788]: return_sense(): [Key/ASC/ASCQ] [4d 00 02]
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (566) (delay 805): 10 00 00 00 02 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_write_filemarks(): WRITE 2 FILEMARKS (566) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: CDB (567) (delay 405): 01 00 00 00 00 00
Mar 19 10:39:15 dbtsm1 vtltape[2788]: ssc_rewind(): REWINDING (567) **
Mar 19 10:39:15 dbtsm1 vtltape[2788]: rewind_tape(): Media is not writable
Many thanks for the testing and detailed analysis.

This sequence does NOT look correct..

The position was already at BOT and it should be valid to write a block of data.
I need to re-examine the code in vtltape.c to figure out why. From the information at hand, it certainly looks like a bug on my end.
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
Can you please check this patch..

It seems to fix the issue for me, but I'd like confirmation :)

worm.patch

FWIW: This fixes the "won't write to WORM media"..

The library media type will be another patch.
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Tiger22
Hi Mark,

Good stuff! The patch worked in that it allowed me to label the tape and bring it into the library as a scratch tape, however I have a number of issues when trying to progress further.

When TSM goes to write to that tape I get a further failure with a TSM message:

ANR1405W Scratch volume mount request denied - no scratch
                          volume available. (SESSION: 6)

I think the following is happening:

1. The WORM tape is labelled and in the library as a scratch tape ready for whichever TSM storage pool needs it.
2. A backup from a client has to write to a storage pool which only has WORM tapes in it.
3. That particular storage pool is currently empty so TSM seeks a scratch tape to use in the library with a media type which meets the WORM cirteria.
4. TSM cannot find a tape that meets that criteria.

So the issue I think is that once the tape is in the library, TSM further queries the library to find a tape with a media type which meets a certain criteria (in this case a WORM LTO4 tape). Could it be that the library is not correctly identifying the media type of the tape back to TSM?

In TSM there is a "show slots" command (example output from my test system given below) which gives some lower level information about the library. The media type for my LTO4 WORM tape is being reported back as a number 427 (standard LTO4 tapes also display the same number 427).

I have observed that an LTO4 tape in TSM ("show slots") comes back as mediaT=427 and an LTO3 tape is being reported as MediaT=417 so specific information about the media generation type in each slot is definitely being pased back to TSM from the VTL.

So the obvious question I have is: should WORM variants of these LTO tapes have different media type numbers from their RW equivalents? Is this where the problem might lie?

I also notice that if I define a second TSM storage pool that can use standard RW as well as WORM LTO media, that TSM will happily allow that WORM tape to be used in that storage pool (no "no scratch volume available" error). However when it tries to further write data to that WORM tape I then get a further error:

ANR8463E LTO volume WW0001LU is write protected.

I include the debug log of that last attempt to write to the tape below.



tsm: DBTSM1>show slots ts3200
PVR slot information for library TS3200.
Library          : TS3200
Product Id       : 3573-TL
Support module   : 2

Mount count      : 0

Drives           : 2
Slots            : 39
Changers         : 1
Import/Exports   : 4

Device           : /dev/IBMchanger1

Drive   0, element 256
Drive   1, element 257

Changer 0, element 1

ImpExp 0, element number 16
ImpExp 1, element number 17
ImpExp 2, element number 18
ImpExp 3, element number 19
Slot 9, status Allocated, element number 4105, barcode present, barcode value <WW0001LU>, devT=LTO, mediaT=427, elemT=ANY

slot element range 4096 - 4134




[root]# tail -f /varlog/messages

Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1211) (delay 1000005): 12 01 83 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1211)
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1212) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [06 29 00]
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1213) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_tur(): Test Unit Ready (1213) ** : No, No tape loaded
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1214) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1214)
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1215) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_tur(): Test Unit Ready (1215) ** : No, No tape loaded
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1216) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1216) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1217) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1217) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1218) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_in(): PERSISTENT RESERVE IN (1218) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: resp_spc_pri(): service action: 1
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1219) (delay 405): 1a 00 10 00 0c 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1219) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1220) (delay 405): 15 10 00 00 0c 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1220) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1221) (delay 805): 1a 08 0f 00 14 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1221) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1222) (delay 405): 15 10 00 00 14 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1222) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:54 dbtsm1 vtltape[6705]: set_mode_compression():  Setting compression
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1223) (delay 405): 1a 08 10 00 14 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1223) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1224) (delay 405): 15 10 00 00 14 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1224) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1225) (delay 405): 1a 08 01 00 10 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1225) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1226) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1226) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1227) (delay 405): 05 00 00 00 00 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_read_block_limits(): READ BLOCK LIMITS (1227) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1228) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1228) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1229) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1229) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1230) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1230) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1231) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1231)
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1232) (delay 405): 12 00 00 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1232)
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1233) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1233)
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1234) (delay 405): 01 00 00 00 00 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_rewind(): REWINDING (1234) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1235) (delay 405): 5f 00 00 00 00 00 00 00 18 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1235) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: CDB (1236) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 20 10:24:54 dbtsm1 vtltape[6705]: ssc_pr_in(): PERSISTENT RESERVE IN (1236) **
Mar 20 10:24:54 dbtsm1 vtltape[6705]: resp_spc_pri(): service action: 1
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1237) (delay 1000005): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1237)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1238) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1238)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1239) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: return_sense(): [Key/ASC/ASCQ] [06 29 00]
Mar 20 10:24:55 dbtsm1 kernel: lin_tape: IBMChgr1----- changer_check_result sensekey: 6 asc: 29 ascq: 0
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1240) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1240)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1241) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_tur(): ** TEST UNIT READY : Returning =>  (1241) Online **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1242) (delay 805): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1242)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1243) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1243)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1244) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1244)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1245) (delay 405): 1a 08 1d 00 18 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_mode_sense(): MODE SENSE 6 (1245) **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1246) (delay 405): b8 14 01 00 00 02 00 00 00 78 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: smc_read_element_status(): READ ELEMENT STATUS (1246) **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1247) (delay 2805): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1247)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1248) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1248)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1249) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_tur(): ** TEST UNIT READY : Returning =>  (1249) Online **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1250) (delay 405): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1250)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1251) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1251)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1252) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1252)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1253) (delay 405): a5 00 00 01 10 09 01 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: smc_move_medium(): MOVE MEDIUM (1253) **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: smc_move_medium(): Moving from slot 4105 to slot 256 using transport 1, Invert media: no
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: move_slot2drive(): About to send cmd: 'lload WW0001LU' to drive 1
Mar 20 10:24:55 dbtsm1 vtltape[6705]: processMessageQ(): Sender id: 20, msg : lload WW0001LU
Mar 20 10:24:55 dbtsm1 vtltape[6705]: loadTape(): Media type 'LTO4' loaded with S/No. : WW0001LU_1426837073
Mar 20 10:24:55 dbtsm1 vtltape[6705]: loadTape(): Write Once Read Many (WORM) media loaded
Mar 20 10:24:55 dbtsm1 vtltape[6705]: loadTape(): Media is not writable
Mar 20 10:24:55 dbtsm1 vtltape[6705]: loadTape(): Setting MediumDensityCode to LTO4 WORM (0x4c) Media type: 0x48
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1254) (delay 25605): 12 01 83 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1254)
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1255) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_tur(): Test Unit Ready (1255) ** : Yes
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1256) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1256) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1257) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1257) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1258) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_pr_in(): PERSISTENT RESERVE IN (1258) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: resp_spc_pri(): service action: 1
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1259) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1259) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1260) (delay 405): 05 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_block_limits(): READ BLOCK LIMITS (1260) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1261) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1261) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1262) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1262) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1263) (delay 405): 34 00 00 00 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): READ POSITION (1263) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): service_action: 0
Mar 20 10:24:55 dbtsm1 vtltape[6705]: resp_read_position(): Positioned at block 0
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1264) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_pr_out(): PERSISTENT RESERVE OUT (1264) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1265) (delay 5): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1265)
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1266) (delay 5): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1266)
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1267) (delay 5): 12 01 83 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_inquiry(): INQUIRY ** (1267)
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1268) (delay 5): 01 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_rewind(): REWINDING (1268) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rewind_tape(): Media is not writable
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1269) (delay 5): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1269) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1270) (delay 5): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1270) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1271) (delay 5): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1271) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1272) (delay 5): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1272) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1273) (delay 5): 1a 00 10 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1273) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1274) (delay 5): 15 10 00 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1274) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1275) (delay 5): 01 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_rewind(): REWINDING (1275) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rewind_tape(): Media is not writable
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1276) (delay 405): 08 02 00 00 50 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rw_6(): READ: 1 block of 80 bytes (1276) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: readBlock(): Expected to find DATA header, found: FILEMARK
Mar 20 10:24:55 dbtsm1 vtltape[6705]: position_blocks_forw(): Filemark encountered: block 4
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [80 00 01]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [20 00 00]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [80 00 01]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1281) (delay 405): 34 00 00 00 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): READ POSITION (1281) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): service_action: 0
Mar 20 10:24:55 dbtsm1 vtltape[6705]: resp_read_position(): Positioned at block 5
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1282) (delay 1205): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1282) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1283) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1283) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1284) (delay 405): 44 01 00 00 00 00 00 01 a4 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_report_density_support(): REPORT MOUNTED MEDIA DENSITY SUPPORT (1284) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1285) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1285) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1286) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1286) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1287) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1287) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1288) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1288) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1289) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1289) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1290) (delay 5): 1a 00 10 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1290) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1291) (delay 5): 15 10 00 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1291) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1292) (delay 405): 44 01 00 00 00 00 00 01 a4 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_report_density_support(): REPORT MOUNTED MEDIA DENSITY SUPPORT (1292) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1293) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1293) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1294) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1294) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1295) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1295) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1296) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1296) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1297) (delay 405): 1a 00 10 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1297) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1298) (delay 5): 15 10 00 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1298) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1299) (delay 405): 01 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_rewind(): REWINDING (1299) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rewind_tape(): Media is not writable
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1300) (delay 405): 08 02 00 00 50 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rw_6(): READ: 1 block of 80 bytes (1300) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: readBlock(): Expected to find DATA header, found: FILEMARK
Mar 20 10:24:55 dbtsm1 vtltape[6705]: position_blocks_forw(): Filemark encountered: block 4
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [80 00 01]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [20 00 00]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [80 00 01]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1305) (delay 405): 34 00 00 00 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): READ POSITION (1305) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_read_position(): service_action: 0
Mar 20 10:24:55 dbtsm1 vtltape[6705]: resp_read_position(): Positioned at block 5
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1306) (delay 4405): 01 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_rewind(): REWINDING (1306) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rewind_tape(): Media is not writable
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1307) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1307) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1308) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1308) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1309) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1309) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1310) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1310) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1311) (delay 405): 1a 00 10 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 6 (1311) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1312) (delay 405): 15 10 00 00 0c 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select(): MODE SELECT 6 (1312) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1313) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: spc_mode_sense(): MODE SENSE 10 (1313) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1314) (delay 405): 0a 00 00 00 50 00
Mar 20 10:24:55 dbtsm1 vtltape[6705]: rw_6(): WRITE: 1 block of 80 bytes (1314) **
Mar 20 10:24:55 dbtsm1 vtltape[6705]: check_restrictions(): Failed attempt to overwrite WORM data
Mar 20 10:24:55 dbtsm1 vtltape[6705]: return_sense(): [Key/ASC/ASCQ] [07 30 0c]
Mar 20 10:24:55 dbtsm1 vtltape[6705]: CDB (1315) (delay 1205): 1b 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 rsyslogd-2177: imuxsock begins to drop messages from pid 6705 due to rate-limiting
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1316) (delay 9205): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1316)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1317) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1317)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1318) (delay 805): 00 00 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_tur(): ** TEST UNIT READY : Returning =>  (1318) Online **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1319) (delay 805): 12 00 00 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1319)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1320) (delay 805): 12 01 80 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1320)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1321) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1321)
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: CDB (1322) (delay 405): a5 00 00 01 01 00 10 09 00 00 00 00
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: smc_move_medium(): MOVE MEDIUM (1322) **
Mar 20 10:24:55 dbtsm1 vtllibrary[6716]: smc_move_medium(): Moving from slot 256 to slot 4105 using transport 1, Invert media: no
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1326) (delay 1000005): 12 01 83 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_inquiry(): INQUIRY ** (1326)
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1327) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: return_sense(): [Key/ASC/ASCQ] [06 29 00]
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1328) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_tur(): Test Unit Ready (1328) ** : No, No tape loaded
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1329) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_inquiry(): INQUIRY ** (1329)
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1330) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_tur(): Test Unit Ready (1330) ** : No, No tape loaded
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1331) (delay 805): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_out(): PERSISTENT RESERVE OUT (1331) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1332) (delay 405): 5f 01 03 00 00 00 00 00 18 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_out(): PERSISTENT RESERVE OUT (1332) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1333) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_in(): PERSISTENT RESERVE IN (1333) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: resp_spc_pri(): service action: 1
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1334) (delay 405): 1a 00 10 00 0c 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 6 (1334) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1335) (delay 405): 15 10 00 00 0c 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select(): MODE SELECT 6 (1335) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1336) (delay 405): 1a 08 0f 00 14 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 6 (1336) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1337) (delay 405): 15 10 00 00 14 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select(): MODE SELECT 6 (1337) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:56 dbtsm1 vtltape[6709]: set_mode_compression():  Setting compression
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1338) (delay 405): 1a 08 10 00 14 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 6 (1338) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1339) (delay 405): 15 10 00 00 14 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select(): MODE SELECT 6 (1339) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_mode_select():  Save Pages: 0, Page Format conforms to T10 standard
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1340) (delay 405): 1a 08 01 00 10 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 6 (1340) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1341) (delay 405): 1a 00 10 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 6 (1341) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1342) (delay 405): 05 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_read_block_limits(): READ BLOCK LIMITS (1342) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1343) (delay 405): 5a 08 24 00 00 00 00 28 08 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 10 (1343) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1344) (delay 405): 5a 08 25 00 00 00 00 28 28 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_mode_sense(): MODE SENSE 10 (1344) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1345) (delay 405): 5f 06 00 00 00 00 00 00 18 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_out(): PERSISTENT RESERVE OUT (1345) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1346) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_inquiry(): INQUIRY ** (1346)
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1347) (delay 405): 12 00 00 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_inquiry(): INQUIRY ** (1347)
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1348) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: spc_inquiry(): INQUIRY ** (1348)
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1349) (delay 405): 01 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_rewind(): REWINDING (1349) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: return_sense(): [Key/ASC/ASCQ] [02 3a 00]
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1350) (delay 405): 5f 00 00 00 00 00 00 00 18 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_out(): PERSISTENT RESERVE OUT (1350) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: CDB (1351) (delay 405): 5e 01 00 00 00 00 00 00 08 00
Mar 20 10:24:56 dbtsm1 vtltape[6709]: ssc_pr_in(): PERSISTENT RESERVE IN (1351) **
Mar 20 10:24:56 dbtsm1 vtltape[6709]: resp_spc_pri(): service action: 1
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1352) (delay 27605): 12 00 00 00 ff 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1352)
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1353) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1353)
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1354) (delay 405): 00 00 00 00 00 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_tur(): ** TEST UNIT READY : Returning =>  (1354) Online **
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1355) (delay 405): 12 00 00 00 ff 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1355)
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1356) (delay 405): 12 01 80 00 ff 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1356)
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1357) (delay 405): 12 01 83 00 ff 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_inquiry(): INQUIRY ** (1357)
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1358) (delay 405): 1a 08 1d 00 18 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: spc_mode_sense(): MODE SENSE 6 (1358) **
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: CDB (1359) (delay 405): b8 14 01 00 00 02 00 00 00 78 00 00
Mar 20 10:24:56 dbtsm1 vtllibrary[6716]: smc_read_element_status(): READ ELEMENT STATUS (1359) **


Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
I think I have a patch ready (tomorrow with luck) that will check each tape 'type' on a READ ELEMENT STATUS
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
Any chance of applying these two patches and testing the library functionality..

Instead of generating media type based on a barcode, this patch opens the media metadata and read the media type..

It does add a cross-dependency of the library code now being dependent on the underlying tape format - for the sake of accuracy.

0003-Update-lib_id-to-be-a-long-across-the-board.patch
0004-vtllibrary-To-report-correct-media-type-a-helper-add.patch
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
BTW: trying WORM setup in NetBackup and its failing. More work still to do.

Sent from my iPhone

On 26 Mar 2015, at 08:21, Mark Harvey [via mhVTL - A Linux Virtual Tape Library] <[hidden email]> wrote:

Any chance of applying these two patches and testing the library functionality..

Instead of generating media type based on a barcode, this patch opens the media metadata and read the media type..

It does add a cross-dependency of the library code now being dependent on the underlying tape format - for the sake of accuracy.

0003-Update-lib_id-to-be-a-long-across-the-board.patch
0004-vtllibrary-To-report-correct-media-type-a-helper-add.patch
Regards from Australia
Mark Harvey



If you reply to this email, your message will be added to the discussion below:
http://mhvtl-a-linux-virtual-tape-library.966029.n3.nabble.com/Using-LTO4-WORM-media-tp4025899p4025907.html
To start a new topic under mhVTL - A Linux Virtual Tape Library, email [hidden email]
To unsubscribe from mhVTL - A Linux Virtual Tape Library, click here.
NAML
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Tiger22
I've tested the patches. There is definitely progress.

After the tape is labelled by TSM and taken into the library as a scratch tape I once again tried a backup from a client node that needs to write to WORM media. TSM now correctly identifies that WORM tape, assigns it to the WORM storage pool, and loads it into a drive to write to. That is a step further than before.

It is at this point now, when data is attempted to be written to the tape, where the backup fails with an error from TSM saying the media is write protected:

03/26/2015 11:09:41      ANR8302E I/O error on drive LTO_DRIVE2
(/dev/IBMtape5)
                          with volume WW0001LU (OP=WRITE, Error Number=1, CC=0, rc
                          = 8, KEY= 07, ASC=30, ASCQ= 0C,
                         
SENSE=F0.00.07.00.00.00.00.58.00.00.00.00.30.0C.00.00.00-
                         
.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.0-
                         
0.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.-
                         
00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00-
                         
.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.0-
                          0.00.00.00.00, Description=An undetermined error has
                          occurred). Refer to the Tivoli Storage Manager
                          documentation on I/O error code
descriptions.   (SESSION:
                          5)
more...   (<ENTER> to continue, 'C' to cancel)

03/26/2015 11:09:41      ANR8463E LTO volume WW0001LU is write
protected. (SESSION:
                          5)
03/26/2015 11:09:41      ANR1411W Access mode for volume WW0001LU now set to
                          "read-only" due to write error. (SESSION: 5)

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
Many thanks for confirmation. I'm at the same point with NetBackup too. More work after the weekend. 

Sent from my iPhone

On 27 Mar 2015, at 20:53, Tiger22 [via mhVTL - A Linux Virtual Tape Library] <[hidden email]> wrote:

I've tested the patches. There is definitely progress.

After the tape is labelled by TSM and taken into the library as a scratch tape I once again tried a backup from a client node that needs to write to WORM media. TSM now correctly identifies that WORM tape, assigns it to the WORM storage pool, and loads it into a drive to write to. That is a step further than before.

It is at this point now, when data is attempted to be written to the tape, where the backup fails with an error from TSM saying the media is write protected:

03/26/2015 11:09:41      ANR8302E I/O error on drive LTO_DRIVE2
(/dev/IBMtape5)
                          with volume WW0001LU (OP=WRITE, Error Number=1, CC=0, rc
                          = 8, KEY= 07, ASC=30, ASCQ= 0C,
                         
SENSE=F0.00.07.00.00.00.00.58.00.00.00.00.30.0C.00.00.00-
                         
.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.0-
                         
0.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.-
                         
00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00-
                         
.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.00.0-
                          0.00.00.00.00, Description=An undetermined error has
                          occurred). Refer to the Tivoli Storage Manager
                          documentation on I/O error code
descriptions.   (SESSION:
                          5)
more...   (<ENTER> to continue, 'C' to cancel)

03/26/2015 11:09:41      ANR8463E LTO volume WW0001LU is write
protected. (SESSION:
                          5)
03/26/2015 11:09:41      ANR1411W Access mode for volume WW0001LU now set to
                          "read-only" due to write error. (SESSION: 5)




If you reply to this email, your message will be added to the discussion below:
http://mhvtl-a-linux-virtual-tape-library.966029.n3.nabble.com/Using-LTO4-WORM-media-tp4025899p4025909.html
To start a new topic under mhVTL - A Linux Virtual Tape Library, email [hidden email]
To unsubscribe from mhVTL - A Linux Virtual Tape Library, click here.
NAML
Regards from Australia
Mark Harvey
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Using LTO4 WORM media

Mark Harvey
Administrator
In reply to this post by Tiger22
Hello Tiger22..

Any chance of sync'ing up with github and trying the latest patches..

I've updated the STK T10K emulation along with the IBM & HP LTO emulations..
Regards from Australia
Mark Harvey
Loading...