Can't get IBM library to work with TSM

Tape drive and auto-loader redirector over iSCSI

Moderators: anton (staff), art (staff), Max (staff), Anatoly (staff)

boxcar
Posts: 10
Joined: Wed Sep 17, 2014 7:59 pm

Fri Nov 14, 2014 3:54 am

I have a working physical library, TS3582 with two LTO3 tape drives iSCSI server from a Hyper-V Windows Storage Server 2012 R2 to RHEL 6.2 virtual machine. When I attempt to load a tape for a database backup I get the following in the TSM error log:

11/13/2014 20:38:16 ANR8300E I/O error on library TS3582 (OP=C0106C03, CC=200,
KEY=FF, ASC=FF, ASCQ=FF, SENSE= **NONE**, Description=The
device indicated a failure condition, but sense data was
unavailable). Refer to the Tivoli Storage Manager
documentation on I/O error code descriptions. (SESSION:
3, PROCESS: 2)

The Starwind log has the following:
11/13 20:38:06.500 2c4694 PR: * Persistent reservation command when standard reservation is active!
11/13 20:38:16.547 2c47b8 C[a3], LIN: recvData returned 10058
11/13 20:38:16.547 2c47b8 C[a3], LIN: *** 'recv' thread: recv failed 10058.
11/13 20:38:18.812 82814 Srv: Accepted iSCSI connection from 192.168.11.102:48195 to 192.168.11.100:3260. (Id = 0xa4)
11/13 20:38:18.812 82814 C[a4], FREE: TCP recvBuf: 65536, sendBuf 65536.
11/13 20:38:18.812 82814 C[a4], FREE: Event - CONNECTED.
11/13 20:38:18.812 82814 C[a4], XPT_UP: T3.
11/13 20:38:19.062 2c4724 C[a4], XPT_UP: Login request: ISID 0x00023d010000, TSIH 0x0000.
11/13 20:38:19.062 2c4724 C[a4], XPT_UP: Event - LOGIN.
11/13 20:38:19.062 2c4724 C[a4], IN_LOGIN: T4.
11/13 20:38:19.062 2c4724 Params: <<< String param 'InitiatorName': received 'iqn.1994-05.com.redhat:eef6bc59b3de', accepted 'iqn.1994-05.com.redhat:eef6bc59b3de'
11/13 20:38:19.062 2c4724 Params: <<< String param 'InitiatorAlias': received 'linuxtsm', accepted 'linuxtsm'
11/13 20:38:19.062 2c4724 Params: <<< String param 'TargetName': received 'iqn.2008-08.com.starwindsoftware:hyperv2.hq.storserver.local-ts3582', accepted 'iqn.2008-08.com.starwindsoftware:hyperv2.hq.storserver.local-ts3582'
11/13 20:38:19.062 2c4724 Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'
11/13 20:38:19.062 2c4724 Params: <<< Enum param 'HeaderDigest': received 'None', accepted 'None'
11/13 20:38:19.062 2c4724 Params: <<< Enum param 'DataDigest': received 'None', accepted 'None'
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'DefaultTime2Wait': received 2, accepted 2
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'DefaultTime2Retain': received 0, accepted 0
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'IFMarker': received No, accepted 0
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'OFMarker': received No, accepted 0
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'ErrorRecoveryLevel': received 0, accepted 0
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'InitialR2T': received No, accepted 0
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'ImmediateData': received Yes, accepted 1
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'MaxBurstLength': received 16776192, accepted 262144
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'FirstBurstLength': received 262144, accepted 262144
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'MaxOutstandingR2T': received 1, accepted 1
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'MaxConnections': received 1, accepted 1
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'DataPDUInOrder': received Yes, accepted 1
11/13 20:38:19.062 2c4724 Params: <<< Boolean param 'DataSequenceInOrder': received Yes, accepted 1
11/13 20:38:19.062 2c4724 Params: <<< Numeric param 'MaxRecvDataSegmentLength': received 262144, accepted 262144
11/13 20:38:19.062 2c4724 T[a4,1]: An old session <a3> from the same Initiator/ISID found. Session reinstatement starting...
11/13 20:38:19.062 2c4724 C[a3], LIN: Close socket.
11/13 20:38:19.062 2c4724 S[a3]: Connection <a3> stat (1)
11/13 20:38:20.078 2c4724 T[a4,1]: Waiting for the old session <a3> to shut down...
11/13 20:38:20.078 2c4724 T[a4,1]: Old session <a3> is still present. Force clean up...
11/13 20:38:36.156 82814 Srv: Accepted iSCSI connection from 192.168.11.102:48196 to 192.168.11.100:3260. (Id = 0xa5)
11/13 20:38:36.156 82814 C[a5], FREE: TCP recvBuf: 65536, sendBuf 65536.

The tape doesn't load. This seems to be a problem with the library because I've manually loaded a tape in a drive and performed the backup, but the library doesn't move the tape to the drive.

I get the same results regardless of how I configure the library/drives on Starwind. I have the same result with two different libraries and lin_tape versions 2.7 and 2.9. Both libraries work with direct physical connections and the TSM server on the physical machine. One also works with Windows 2012 R2 Hypev-V when served as a virtual SAN device to a Windows 2012 R2 Storage Server. Unfortunately, I can't make the virtual SAN work with RHEL.

I can't find another topic where anyone has tried this.

Any suggestions?

Thanks
User avatar
anton (staff)
Site Admin
Posts: 4008
Joined: Fri Jun 18, 2004 12:03 am
Location: British Virgin Islands
Contact:

Fri Nov 14, 2014 10:08 am

1) You need to limit request size @ Linux VM. Similar to what we recommend telling for Windows. See:

http://www.starwindsoftware.com/forums/ ... =26&t=1089

2) Please don't send us parts of the logs. We need full one. See:

http://www.starwindsoftware.com/forums/ ... ?f=5&t=740

P.S. Moving this to "Tape Redirector" part of the forum...
Regards,
Anton Kolomyeytsev

Chief Technology Officer & Chief Architect, StarWind Software

Image
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Fri Nov 14, 2014 5:02 pm

I sent the complete log file to the support@storwindsoftware.com - it is case#00012095.

Thanks
sidecar
User avatar
anton (staff)
Site Admin
Posts: 4008
Joined: Fri Jun 18, 2004 12:03 am
Location: British Virgin Islands
Contact:

Fri Nov 14, 2014 6:38 pm

Thank you!
sidecar wrote:I sent the complete log file to the support@storwindsoftware.com - it is case#00012095.

Thanks
sidecar
Regards,
Anton Kolomyeytsev

Chief Technology Officer & Chief Architect, StarWind Software

Image
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Fri Nov 14, 2014 8:19 pm

Please let me know if there is anything else I can get for you.

sidecar
User avatar
Anatoly (staff)
Staff
Posts: 1675
Joined: Tue Mar 01, 2011 8:28 am
Contact:

Mon Nov 17, 2014 12:31 pm

Hi Just want to let you know that we received the logs and currently R&D is investigating them. We will let you know should we have any result or additional information request.
Best regards,
Anatoly Vilchinsky
Global Engineering and Support Manager
www.starwind.com
av@starwind.com
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Tue Nov 18, 2014 4:01 pm

I really need to get an update on this issue so I can resolve the problem.

Thanks
User avatar
Anatoly (staff)
Staff
Posts: 1675
Joined: Tue Mar 01, 2011 8:28 am
Contact:

Wed Nov 19, 2014 11:38 am

We see that sessions are dropping due to timeouts (5 seconds). Theoretically if you could change this in the application that uses tapes that should help. Please try that out and let us know if that helped.

Thank you.
Best regards,
Anatoly Vilchinsky
Global Engineering and Support Manager
www.starwind.com
av@starwind.com
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Wed Nov 19, 2014 3:42 pm

The mount wait is 60 Minutes at the moment. I don't know of any other setting that would cause this timeout. TSM is getting an I/O error msg back from the request to move a tape from a slot to a drive. From the library interface we don't see any attempt to move a tape to a drive. From the front of the library we never see it move in an attempt to move a tape from a slot to a drive.

If I set everything up as a manual library and issue a command to backup data to tape and then manually move the tape to a drive all works great. We just cannot get this running as an automated library.

Do you know of any other file on the Linux server that might contain any such setting you believe might need to be changed?

Thanks
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Fri Nov 21, 2014 5:04 pm

Is there any update to the latest log I sent after changing the following settings:

Here is the latest log after changing the following to 30:

/etc/iscsi/iscsid.conf


node.conn[0].timeo.noop_out_interval
node.conn[0].timeo.noop_out_timeout

The library failed to load a tape and failed with an I/o twice in under 30 seconds.

Thanks
Val (staff)
Posts: 496
Joined: Tue Jun 29, 2004 8:38 pm

Fri Nov 21, 2014 5:21 pm

Hi, sidecar!
It seems you are the first person at the forum who using the Starwind Tape Redirector with Linux clients.

But according to http://www.open-iscsi.org/docs/README the node.session.timeo.replacement_timeout parameter of iscsid.conf is the one to be tuned.
Please look at the parameter at iscsid.conf (I guess it is set to 5) and change it to 300 or greater value that solves the problem with iSCSI session reinstatement.
Best regards,
Valeriy
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Fri Nov 21, 2014 7:04 pm

Thanks but the credit goes to my boss boxcar for being the first. I found and changed that setting to 360 - rebooted - request to mount a tape fails just as fast. Please let me know if you need the latest log or any other information.

Thanks
Val (staff)
Posts: 496
Joined: Tue Jun 29, 2004 8:38 pm

Fri Nov 21, 2014 8:51 pm

sidecar wrote:Thanks but the credit goes to my boss boxcar for being the first. I found and changed that setting to 360 - rebooted - request to mount a tape fails just as fast. Please let me know if you need the latest log or any other information.
Yes, I'd like to look at the StarWind log and the iscsid.conf.
Best regards,
Valeriy
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Mon Nov 24, 2014 3:50 pm

Here are the requested files.
sidecar
Posts: 10
Joined: Fri Nov 14, 2014 4:54 pm

Mon Nov 24, 2014 3:53 pm

I added both files as attachments. From manage attachments I see no post. Is there an e-mail address I should send them to?

Thanks
Post Reply