"'recv' thread: recv failed 10058" - Linux initiator

melix · Tue Sep 08, 2009 8:24 am

Hi,

I have Linux SLES10SP2 virtual server. When trying to discover StarWind target I get the error message "LIN: *** 'recv' thread: recv failed 10058".

starwind.log:
============
9/8 12:20:25.316 3b0 Srv: StarWind iSCSI Target v4.2.2 (Build 20090817, Win32)
9/8 12:20:25.316 3b0 Srv: Built Aug 17 2009 21:11:25
9/8 12:20:25.316 3b0 Srv: Windows Server 2003 R2 Standard Edition Service Pack 2 (Build 3790)
9/8 12:20:25.316 3b0 Srv: System CPU count: 1
9/8 12:20:25.316 3b0 Srv: Licensed to: 'XXXX, 'YYYY', (#1, 0, 20091007).
9/8 12:20:25.316 3b0 Srv: Config file: 'StarWind.cfg'
9/8 12:20:25.332 3b0 conf: Variable 'LogLevel' is set to '1'.
9/8 12:20:25.332 3b0 conf: Variable 'LogMask' is set to '0x8fffffff'.
9/8 12:20:25.332 3b0 conf: Variable 'Port' is set to '3260'.
9/8 12:20:25.332 3b0 conf: Variable 'Interface' is set to '0.0.0.0'.
9/8 12:20:25.332 3b0 conf: Variable 'Login' is set to ''.
9/8 12:20:25.332 3b0 conf: Variable 'Password' is set to '##1B2M2Y8AsgTpgAmY7PhCfg=='.
9/8 12:20:25.332 3b0 conf: Variable 'MinBufferSize' is set to '65536'.
9/8 12:20:25.332 3b0 conf: Variable 'AlignmentMask' is set to '0x0000'.
9/8 12:20:25.332 3b0 conf: Variable 'MaxPendingRequests' is set to '64'.
9/8 12:20:25.332 3b0 conf: Variable 'iScsiPingPeriod' is set to '0'.
9/8 12:20:25.332 3b0 RAM: SscPort_Init: (build 20090817, built Aug 17 2009 21:11:09)
VendorId = ' '
ProductId = ' '
Revision = '0001'
9/8 12:20:25.332 3b0 conf: 'RamDisk.dll' loaded successfully.
9/8 12:20:25.347 3b0 IMG: SscPort_Init: Parse ImageDir: '*|cmdfv|My Computer|img'
9/8 12:20:25.347 3b0 IMG: *SscPort_Init:
Dirname: '*'
Rights: 0x1f
Alias: 'My Computer'
Extensions: 'img'
9/8 12:20:25.347 3b0 IMG: SscPort_Init: Comment : ''
9/8 12:20:25.347 3b0 IMG: SscPort_Init: (build 20090817, built Aug 17 2009 21:11:10)
VendorId = ' '
ProductId = ' '
Revision = '0001'
DefImageDir = '*\'
Volumes = 0
ExeDir = 'C:\Program Files\StarWind Software\StarWind\'
9/8 12:20:25.347 3b0 conf: 'ImageFile.dll' loaded successfully.
9/8 12:20:25.347 3b0 VDVD: *SscPort_Init:
Dirname: '*'
Rights: 0x18
Alias: 'My Computer'
Extensions: 'mds,iso'
9/8 12:20:25.347 3b0 conf: 'VirtualDvd.dll' loaded successfully.
9/8 12:20:25.347 3b0 IBV: *SscPort_Init:
Dirname: '*'
Rights: 0x1f
Alias: 'My Computer'
Extensions: 'ibv'
9/8 12:20:25.347 3b0 IBV: *SscPort_Init:
Dirname: '*'
Rights: 0x1e
Alias: 'Snapshots'
Extensions: 'ibvss'
9/8 12:20:25.347 3b0 IBV: *SscPort_Init:
Dirname: '*'
Rights: 0x9
Alias: 'Image Files'
Extensions: 'img,dat'
9/8 12:20:25.347 3b0 IBV: SscPort_Init: (build 20090817, built Aug 17 2009 21:11:13)
VendorId = ' '
ProductId = ' '
Revision = '0001'
ImageDir = '*\'
ExeDir = 'C:\Program Files\StarWind Software\StarWind\'
9/8 12:20:25.347 3b0 conf: 'IBVolume.dll' loaded successfully.
9/8 12:20:25.347 3b0 MIR: *SscPort_Init:
Dirname: '*'
Rights: 0x1f
Alias: 'Mirror Volumes'
Extensions: 'mir'
9/8 12:20:25.347 3b0 MIR: *SscPort_Init:
Dirname: '*'
Rights: 0xc
Alias: 'Image Files'
Extensions: 'img,dat'
9/8 12:20:25.347 3b0 conf: 'Mirror.dll' loaded successfully.
9/8 12:20:25.347 3b0 DSKBR: SscPort_Init: (built Aug 17 2009 21:11:17)
VendorId = ' '
ProductId = ' '
Revision = '0001'
ExeDir = 'C:\Program Files\StarWind Software\StarWind\'
9/8 12:20:25.347 3b0 conf: 'DiskBridge.dll' loaded successfully.
9/8 12:20:25.347 3b0 VTAPE: SscPort_Init: Parse ImageDir: '*|cmdfv|My Computer|vtl'
9/8 12:20:25.347 3b0 VTAPE: *SscPort_Init:
Dirname: '*'
Rights: 0x1f
Alias: 'My Computer'
Extensions: 'vtl'
9/8 12:20:25.347 3b0 VTAPE: SscPort_Init: Comment : ''
9/8 12:20:25.347 3b0 VTAPE: *** SscPort_Init: Logging level is set to 1.
9/8 12:20:25.347 3b0 VTAPE: *** SscPort_Init: DBG_ERROR statements are ON.
9/8 12:20:25.347 3b0 VTAPE: SscPort_Init: (built Jun 7 2009 10:58:28)
VendorId = ' '
ProductId = ' '
Revision = ' '
DefImageDir = '*\'
Volumes = 0
ExeDir = 'C:\Program Files\StarWind Software\StarWind\'
9/8 12:20:25.347 3b0 VTAPE: *** TapeEmulCtrlApiStart: StarWind VTL License Type is 3
9/8 12:20:25.347 3b0 VTAPE: *** TapeEmulCtrlApiStart: This Enterprise Edition supports a maximum of 64 devices, each up to 1048576 MB in length.
9/8 12:20:25.347 3b0 conf: 'VirtualTape.dll' loaded successfully.
9/8 12:20:25.347 3b0 S: SymId: 'DiskBridge0': Assigned target name: 'iqn.2003-06.com.rocketdivision.starwind.server-2.diskbridge0', alias 'iqn.2003-06.com.rocketdivision.starwind.server-2.diskbridge0'
9/8 12:20:25.347 3b0 DSKBR: SscPort_Create: Accessing RAW Disk Device '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}'
9/8 12:20:25.347 3b0 DSKBR: SscPort_Create: Opening device 'DiskBridge0', '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}', async=1, readonly=0.
9/8 12:20:25.347 3b0 IMG: ImageFile_Create: '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}' is a RAW volume/disk.
9/8 12:20:25.347 3b0 IMG: ImageFile_Create: '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}': type 2, geometry: sct 63, trks 255, cyl 2610, TotalSectors: 41943040
9/8 12:20:25.347 3b0 IMG: ImageFile_Create: VendorId 'VMware ', ProductId 'Virtual disk ', Revision '1.0 ', Serial '1E046F34CAD1F278'
9/8 12:20:25.347 3b0 Tgt: : parameter 'file', value '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}'.
9/8 12:20:25.347 3b0 Tgt: : parameter 'asyncmode', value 'yes'.
9/8 12:20:25.347 3b0 Tgt: : parameter 'ImageSizeLow', value '0'.
9/8 12:20:25.347 3b0 Tgt: : parameter 'ImageSizeHigh', value '5'.
9/8 12:20:25.347 3b0 Tgt: : parameter 'readonly', value 'no'.
9/8 12:20:25.347 3b0 S: iqn.2003-06.com.rocketdivision.starwind.server-2.diskbridge0: 1 session(s) allowed.
9/8 12:20:25.347 3b0 conf: Target [0x000BFEF8] has been created. Device 'DiskBridge0' is accesible as target 'iqn.2003-06.com.rocketdivision.starwind.server-2.diskbridge0'.
9/8 12:20:25.347 3b0 conf: Variable 'AccessPolicy' is set to 'allow'.
9/8 12:20:25.347 3b0 Srv: Refreshing device list (complete)...
9/8 12:20:25.363 3b0 Srv: Found SPTI device '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&000#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}': 'VMware Virtual disk 1.0 '
9/8 12:20:25.363 3b0 Srv: Found SPTI device '\\?\scsi#disk&ven_vmware&prod_virtual_disk&rev_1.0#4&3a739529&0&010#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}': 'VMware Virtual disk 1.0 '
9/8 12:20:25.363 3b0 Srv: Found SPTI device '\\?\ide#cdromnecvmwar_vmware_ide_cdr00_______________1.00____#3030303030303030303030303030303030303130#{53f56308-b6bf-11d0-94f2-00a0c91efb8b}': ' NECVMWar VMware IDE CDR00 1.00'
9/8 12:20:25.363 708 conf: Waiting for Control connections at 0.0.0.0:3261 ...
9/8 12:20:25.363 3b0 Srv: Waiting for iSCSI connections at 10.6.96.38:3260 ...
9/8 12:20:25.378 3b0 Srv: Waiting for iSCSI connections at 127.0.0.1:3260 ...
9/8 12:21:30.535 3b0 Srv: Accepted iSCSI connection to 10.6.96.38:3260 from 10.6.96.36:38580. (Id = 0x1)
9/8 12:21:30.535 3b0 C[1], FREE: Event - CONNECTED.
9/8 12:21:30.535 3b0 C[1], XPT_UP: T3.
9/8 12:21:30.535 af4 C[1], XPT_UP: Login request: ISID 0x00023d000000, TSIH 0x0000.
9/8 12:21:30.535 af4 C[1], XPT_UP: Event - LOGIN.
9/8 12:21:30.535 af4 C[1], IN_LOGIN: T4.
9/8 12:21:30.535 af4 Params: <<< String param 'InitiatorName': received 'iqn.1996-04.de.suse:01:15e8f191c4ef', accepted 'iqn.1996-04.de.suse:01:15e8f191c4ef'
9/8 12:21:30.535 af4 Params: <<< String param 'InitiatorAlias': received 'oranode1', accepted 'oranode1'
9/8 12:21:30.535 af4 Params: <<< Enum param 'SessionType': received 'Discovery', accepted 'Discovery'
9/8 12:21:30.535 af4 Params: <<< Enum param 'HeaderDigest': received 'None', accepted 'None'
9/8 12:21:30.535 af4 Params: <<< Enum param 'DataDigest': received 'None', accepted 'None'
9/8 12:21:30.535 af4 Params: <<< Numeric param 'DefaultTime2Wait': received 0, accepted 0
9/8 12:21:30.535 af4 Params: <<< Numeric param 'DefaultTime2Retain': received 0, accepted 0
9/8 12:21:30.535 af4 Params: <<< Boolean param 'IFMarker': received No, accepted 0
9/8 12:21:30.535 af4 Params: <<< Boolean param 'OFMarker': received No, accepted 0
9/8 12:21:30.535 af4 Params: <<< Numeric param 'ErrorRecoveryLevel': received 0, accepted 0
9/8 12:21:30.535 af4 Params: <<< Numeric param 'MaxRecvDataSegmentLength': received 32768, accepted 32768
9/8 12:21:30.535 af4 Params: >>> ErrorRecoveryLevel=0.
9/8 12:21:30.535 af4 Params: >>> HeaderDigest=None.
9/8 12:21:30.535 af4 Params: >>> DataDigest=None.
9/8 12:21:30.535 af4 Params: >>> OFMarker=No.
9/8 12:21:30.535 af4 Params: >>> IFMarker=No.
9/8 12:21:30.535 af4 Params: >>> InitialR2T=No.
9/8 12:21:30.535 af4 Params: >>> ImmediateData=Yes.
9/8 12:21:30.535 af4 Params: >>> MaxRecvDataSegmentLength=262144.
9/8 12:21:30.535 af4 Params: >>> MaxBurstLength=262144.
9/8 12:21:30.535 af4 Params: >>> FirstBurstLength=262144.
9/8 12:21:30.535 af4 Params: >>> DefaultTime2Wait=0.
9/8 12:21:30.535 af4 Params: >>> DefaultTime2Retain=0.
9/8 12:21:30.535 af4 Params: >>> MaxOutstandingR2T=1.
9/8 12:21:30.535 af4 Params: >>> DataPDUInOrder=Yes.
9/8 12:21:30.535 af4 Params: >>> DataSequenceInOrder=Yes.
9/8 12:21:30.535 3ac T[1,1]: session 0x1, connection 0x1 : end of stage 1, next stage 3.
9/8 12:21:30.535 3ac C[1], IN_LOGIN: Event - LOGIN_ACCEPT.
9/8 12:21:30.535 3ac C[1], LIN: T5.
9/8 12:21:30.550 af4 C[1], LIN: recvData returned 10058
9/8 12:21:30.550 af4 C[1], LIN: *** 'recv' thread: recv failed 10058.
9/8 12:21:47.113 708 conf: Accepted control connection from 127.0.0.1:3764.

Please, help me resolve this.

Thank you in advance.

Sincerely,
Melix

Robert (staff) · Wed Sep 09, 2009 11:12 am

Melix,

What Linux iSCSI Initiator do you use? Can you connect from other (non-Linux) Pcs?

Thanks

melix · Wed Sep 09, 2009 11:40 am

Hi, Robert.

I use iscsiadm v 2.0-868.
I have tested StarPort at my Windows XP workstation. It works fine with the same target disk.

Sinserely,
Melix.

Robert (staff) · Thu Sep 10, 2009 12:34 pm

Hello Melix,

And what exactly happens on the Initiator side? Do you see any error messages other messages?

Also, did you try using other iSCSI Initiators like Open iSCSI Initiator 2.0?

Thanks.

melix · Mon Sep 14, 2009 6:25 am

Hello, Robert.

The problem was in the GUI tool "iSCSI Initiator", which uses iscsiadm internally (as I think). The GUI tool works fine for Linux targets, but creates wrong configuration files for StarWind targets. To solve the problem, I have used iscsiadm at command line and edited configs by hands.

Sincerely,
Sergey.

Robert (staff) · Mon Sep 14, 2009 7:32 am

Glad to hear that!

Thanks

peper · Wed Mar 24, 2010 8:43 pm

Could you post any details on what exactly was wrong with the config?

Wed Mar 24, 2010 9:42 pm

We'd love to get hands over them as well

Just FOI. Thanks!

balboa41 · Tue Apr 06, 2010 9:58 pm

So there are no details or clues on what was wrong? I am having the same issue, thanks.

Tue Apr 06, 2010 10:05 pm

Re: "'recv' thread: recv failed 10058" - Linux initiator
by melix » Mon Sep 14, 2009 6:25 am

Hello, Robert.

The problem was in the GUI tool "iSCSI Initiator", which uses iscsiadm internally (as I think). The GUI tool works fine for Linux targets, but creates wrong configuration files for StarWind targets. To solve the problem, I have used iscsiadm at command line and edited configs by hands.

Sincerely,
Sergey.