Page 1 of 1

Trouble connecting to iSCSI target

Posted: Fri Sep 14, 2012 2:49 pm
by jason.bashaw
Trying to connect to iSCSI target from Microsoft Systems Center Virtual Machine Manager and I keep getting this error: Could not retrieve a certificate from the 10.20.0.2 server because of the error: The underlying connection was closed: An unexpected error occurred on a send.

Specify a valid server name and port.

ID: 20909
Details: An existing connection was forcibly closed by the remote host (0x80072746)

Server and port are both valid. I have instances of Xen Server that are attached to this target as well. Any help would be appreciated. Log from today below.

9/14 7:39:22.335 35a4 Srv: Removing target 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01' [FORCE]...
9/14 7:39:22.347 35a4 C[1], LIN: Event - SHUTDOWN.
9/14 7:39:22.347 35a4 C[1], LOGOUT_REQUESTED: T11.
9/14 7:39:22.347 35a4 C[2], LIN: Event - SHUTDOWN.
9/14 7:39:22.347 35a4 C[2], LOGOUT_REQUESTED: T11.
9/14 7:39:22.347 35a4 Tgt: iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01: device 'DDDisk1' is detached.
9/14 7:39:22.389 1ac C[1], LOGOUT_REQUESTED: Event - LOGOUT.
9/14 7:39:22.390 1ac C[1], IN_LOGOUT: T9/10.
9/14 7:39:22.390 108c C[1], IN_LOGOUT: Event - LOGOUT_ACCEPT.
9/14 7:39:22.390 108c C[1], FREE: T13.
9/14 7:39:22.390 4594 C[1], FREE: recvData returned 10054
9/14 7:39:22.389 1d80 C[2], LOGOUT_REQUESTED: Event - LOGOUT.
9/14 7:39:22.395 1d80 C[2], IN_LOGOUT: T9/10.
9/14 7:39:22.403 35a4 PR: Set Unit attention 0x3f/0xe for session 0x1 from iqn.1991-05.com.microsoft:symhyper-v-01.symcominc.office,400001370001.
9/14 7:39:22.404 35a4 PR: Set Unit attention 0x3f/0xe for session 0x2 from iqn.1991-05.com.microsoft:sym-000125.symcominc.office,400001370000.
9/14 7:39:22.404 35a4 Tgt: iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01: device 'ImageFile1' is detached.
9/14 7:39:22.417 2df4 C[2], IN_LOGOUT: Event - LOGOUT_ACCEPT.
9/14 7:39:22.418 2df4 C[2], FREE: T13.
9/14 7:39:22.420 2b00 C[2], FREE: recvData returned 10058
9/14 7:39:22.430 35a4 Srv: Target 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01' has been removed.
9/14 7:39:22.511 1ac error: assertion failed: c:\_starwind\_v5\starwind\service\common\fn_common.cpp:28 (isEmpty())
9/14 7:39:22.511 3d14 Srv: Accepted iSCSI connection from 192.168.1.169:55234 to 10.20.0.2:3260. (Id = 0x1f)
9/14 7:39:22.511 1ac Tgt: close 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01': 1 session(s) opened, 65535 more allowed.
9/14 7:39:22.511 3d14 C[1f], FREE: Event - CONNECTED.
9/14 7:39:22.511 3d14 C[1f], XPT_UP: T3.
9/14 7:39:22.512 3ba0 C[1f], XPT_UP: Login request: ISID 0x400001370001, TSIH 0x0000.
9/14 7:39:22.512 1d80 error: assertion failed: c:\_starwind\_v5\starwind\service\common\fn_common.cpp:28 (isEmpty())
9/14 7:39:22.512 1d80 Tgt: close 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01': 0 session(s) opened, 65536 more allowed.
9/14 7:39:22.512 3ba0 C[1f], XPT_UP: Event - LOGIN.
9/14 7:39:22.512 3ba0 C[1f], IN_LOGIN: T4.
9/14 7:39:22.513 3ba0 Params: <<< String param 'InitiatorName': received 'iqn.1991-05.com.microsoft:symhyper-v-01.symcominc.office', accepted 'iqn.1991-05.com.microsoft:symhyper-v-01.symcominc.office'
9/14 7:39:22.513 3ba0 Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'
9/14 7:39:22.513 3ba0 Params: <<< String param 'TargetName': received 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01', accepted 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01'
9/14 7:39:22.513 3ba0 Params: <<< Enum param 'AuthMethod': received 'None', accepted 'None'
9/14 7:39:22.513 3ba0 T[1f,1]: Login request: target 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01' does not exists.
9/14 7:39:22.513 2490 C[1f], IN_LOGIN: Event - LOGIN_REJECT.
9/14 7:39:22.513 2490 C[1f], FREE: T7.
9/14 7:39:22.515 3d14 Srv: Accepted iSCSI connection from 10.20.0.2:39081 to 10.20.0.2:3260. (Id = 0x20)
9/14 7:39:22.515 3d14 C[20], FREE: Event - CONNECTED.
9/14 7:39:22.515 3d14 C[20], XPT_UP: T3.
9/14 7:39:22.516 2de8 C[20], XPT_UP: Login request: ISID 0x400001370000, TSIH 0x0000.
9/14 7:39:22.516 2de8 C[20], XPT_UP: Event - LOGIN.
9/14 7:39:22.516 2de8 C[20], IN_LOGIN: T4.
9/14 7:39:22.516 2de8 Params: <<< String param 'InitiatorName': received 'iqn.1991-05.com.microsoft:sym-000125.symcominc.office', accepted 'iqn.1991-05.com.microsoft:sym-000125.symcominc.office'
9/14 7:39:22.516 2de8 Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'
9/14 7:39:22.516 2de8 Params: <<< String param 'TargetName': received 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01', accepted 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01'
9/14 7:39:22.516 2de8 Params: <<< Enum param 'AuthMethod': received 'None', accepted 'None'
9/14 7:39:22.516 2de8 T[20,1]: Login request: target 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-xenvol01' does not exists.
9/14 7:39:22.516 32d4 C[20], IN_LOGIN: Event - LOGIN_REJECT.
9/14 7:39:22.516 32d4 C[20], FREE: T7.
9/14 7:39:32.574 3214 Srv: Remove Complete '\\?\SCSI#Disk&Ven_ROCKET&Prod_DEDUP_DISK#1&1c121344&0&000000#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}'
9/14 7:39:32.653 3214 Srv: Remove Complete '\\?\SCSI#Disk&Ven_ROCKET&Prod_IMAGEFILE#1&1c121344&0&000001#{53f56307-b6bf-11d0-94f2-00a0c91efb8b}'
9/14 7:39:40.915 35a4 Srv: Updating target 0000000001BC92B0 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-hyperv01', device list 'DDDisk1'...
9/14 7:39:40.915 35a4 Tgt: : parameter 'DataPath', value 'Data\E\XENVOL01.spdata'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'ImageSizeLow', value '0'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'ImageSizeHigh', value '256'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'MountStatus', value '2'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'MountProgress', value '1'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'MetadataPath', value 'Metadata\E\XENVOL01.spmetadata'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'BitmapPath', value 'My Computer\E\XENVOL01.spbitmap'.
9/14 7:39:40.915 35a4 Tgt: : parameter 'SnapshotsDisabled', value 'yes'.
9/14 7:39:40.915 35a4 Tgt: : parameter '#_TargetName_#', value 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-hyperv01'.
9/14 7:39:40.915 35a4 Tgt: iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-hyperv01: device DDDisk1: new LUN 0 mapped to target LUN 0.
9/14 7:39:40.915 35a4 Tgt: iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-hyperv01: attached device DDDisk1 (found 1 LUNs).
9/14 7:39:40.915 35a4 conf: Target [0x0000000001BC92B0] 'iqn.2008-08.com.starwindsoftware:sym-000125.symcominc.office-hyperv01' has been updated, 1 devices attached.
9/14 7:43:04.407 2b98 conf: Accepted control connection from 192.168.1.172:53022.
9/14 7:43:04.412 2b98 conf: Accepted control connection from 192.168.1.172:53023.
9/14 7:43:04.424 1ae4 conf: Send error 10053!
9/14 7:43:04.424 88c conf: Send error 10053!
9/14 7:43:04.424 1ae4 conf: Send error 10053!
9/14 7:43:04.424 88c conf: Send error 10053!
9/14 7:43:04.424 1ae4 conf: Send error 10053!
9/14 7:43:04.424 88c conf: Send error 10053!
9/14 7:43:04.424 88c conf: Control connection closed.
9/14 7:43:04.424 1ae4 conf: Control connection closed.
9/14 7:43:30.399 2b98 conf: Accepted control connection from 192.168.1.172:53025.
9/14 7:43:30.401 1358 conf: Control connection closed.
9/14 7:43:30.405 2b98 conf: Accepted control connection from 192.168.1.172:53026.
9/14 7:43:30.406 2f90 conf: Control connection closed.
9/14 7:43:30.411 2b98 conf: Accepted control connection from 192.168.1.172:53027.
9/14 7:43:30.412 4b40 conf: Control connection closed.
9/14 7:43:30.414 2b98 conf: Accepted control connection from 192.168.1.172:53028.
9/14 7:43:30.416 2328 conf: Control connection closed.
9/14 7:43:30.419 2b98 conf: Accepted control connection from 192.168.1.172:53029.
9/14 7:43:30.420 4150 conf: Control connection closed.
9/14 7:43:30.424 2b98 conf: Accepted control connection from 192.168.1.172:53030.
9/14 7:43:30.425 46e4 conf: Control connection closed.
9/14 7:43:30.428 2b98 conf: Accepted control connection from 192.168.1.172:53031.
9/14 7:43:30.428 24b4 conf: Control connection closed.
9/14 7:43:30.432 2b98 conf: Accepted control connection from 192.168.1.172:53032.
9/14 7:43:30.433 2418 conf: Control connection closed.
9/14 7:43:30.436 2b98 conf: Accepted control connection from 192.168.1.172:53033.
9/14 7:43:30.438 27d8 conf: Control connection closed.
9/14 7:43:30.441 2b98 conf: Accepted control connection from 192.168.1.172:53034.
9/14 7:43:30.443 3a9c conf: Control connection closed.
9/14 7:43:30.445 2b98 conf: Accepted control connection from 192.168.1.172:53035.
9/14 7:43:30.447 231c conf: Control connection closed.
9/14 7:43:30.449 2b98 conf: Accepted control connection from 192.168.1.172:53036.
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.452 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Send error 10053!
9/14 7:43:30.453 fac conf: Control connection closed.
9/14 7:43:46.659 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53037 to 10.20.0.2:3260. (Id = 0x21)
9/14 7:43:46.659 3d14 C[21], FREE: Event - CONNECTED.
9/14 7:43:46.659 3d14 C[21], XPT_UP: T3.
9/14 7:43:46.660 3390 C[21], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.660 3390 C[21], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.663 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53038 to 10.20.0.2:3260. (Id = 0x22)
9/14 7:43:46.663 3d14 C[22], FREE: Event - CONNECTED.
9/14 7:43:46.663 3d14 C[22], XPT_UP: T3.
9/14 7:43:46.664 1da4 C[22], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.664 1da4 C[22], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.667 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53039 to 10.20.0.2:3260. (Id = 0x23)
9/14 7:43:46.667 3d14 C[23], FREE: Event - CONNECTED.
9/14 7:43:46.667 3d14 C[23], XPT_UP: T3.
9/14 7:43:46.668 1a80 C[23], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.668 1a80 C[23], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.671 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53040 to 10.20.0.2:3260. (Id = 0x24)
9/14 7:43:46.671 3d14 C[24], FREE: Event - CONNECTED.
9/14 7:43:46.671 3d14 C[24], XPT_UP: T3.
9/14 7:43:46.672 3edc C[24], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.672 3edc C[24], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.675 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53041 to 10.20.0.2:3260. (Id = 0x25)
9/14 7:43:46.676 3d14 C[25], FREE: Event - CONNECTED.
9/14 7:43:46.676 3d14 C[25], XPT_UP: T3.
9/14 7:43:46.676 3bf8 C[25], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.676 3bf8 C[25], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.680 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53042 to 10.20.0.2:3260. (Id = 0x26)
9/14 7:43:46.680 3d14 C[26], FREE: Event - CONNECTED.
9/14 7:43:46.680 3d14 C[26], XPT_UP: T3.
9/14 7:43:46.681 2784 C[26], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.681 2784 C[26], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.684 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53043 to 10.20.0.2:3260. (Id = 0x27)
9/14 7:43:46.684 3d14 C[27], FREE: Event - CONNECTED.
9/14 7:43:46.684 3d14 C[27], XPT_UP: T3.
9/14 7:43:46.684 3070 C[27], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.684 3070 C[27], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.688 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53044 to 10.20.0.2:3260. (Id = 0x28)
9/14 7:43:46.688 3d14 C[28], FREE: Event - CONNECTED.
9/14 7:43:46.688 3d14 C[28], XPT_UP: T3.
9/14 7:43:46.688 4848 C[28], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.688 4848 C[28], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.692 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53045 to 10.20.0.2:3260. (Id = 0x29)
9/14 7:43:46.692 3d14 C[29], FREE: Event - CONNECTED.
9/14 7:43:46.692 3d14 C[29], XPT_UP: T3.
9/14 7:43:46.692 2680 C[29], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.692 2680 C[29], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.695 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53046 to 10.20.0.2:3260. (Id = 0x2a)
9/14 7:43:46.695 3d14 C[2a], FREE: Event - CONNECTED.
9/14 7:43:46.695 3d14 C[2a], XPT_UP: T3.
9/14 7:43:46.696 15ac C[2a], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.696 15ac C[2a], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.699 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53047 to 10.20.0.2:3260. (Id = 0x2b)
9/14 7:43:46.699 3d14 C[2b], FREE: Event - CONNECTED.
9/14 7:43:46.699 3d14 C[2b], XPT_UP: T3.
9/14 7:43:46.700 3090 C[2b], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.700 3090 C[2b], FREE: *** 'recv' thread: recv failed 10058.
9/14 7:43:46.705 3d14 Srv: Accepted iSCSI connection from 192.168.1.172:53048 to 10.20.0.2:3260. (Id = 0x2c)
9/14 7:43:46.705 3d14 C[2c], FREE: Event - CONNECTED.
9/14 7:43:46.705 3d14 C[2c], XPT_UP: T3.
9/14 7:43:46.705 151c C[2c], XPT_UP: Login request excepted, got 0x10.
9/14 7:43:46.705 151c C[2c], FREE: *** 'recv' thread: recv failed 10058.

Re: Trouble connecting to iSCSI target

Posted: Sun Sep 16, 2012 6:27 am
by Anatoly (staff)
I have a couple of questions that will help us to clarify the situation:
-are you evaluating SMI-S provider?
-what starwind build are you using?
-what starwind device type are you running?

Re: Trouble connecting to iSCSI target

Posted: Tue Sep 18, 2012 8:16 pm
by jason.bashaw
-are you evaluating SMI-S provider?
Not sure what you are asking (the SMI-S threw me).

-what starwind build are you using?
5.8.2060

-what starwind device type are you running?
deduplicated disk attached to iSCSI target

Re: Trouble connecting to iSCSI target

Posted: Tue Sep 18, 2012 8:27 pm
by anton (staff)
1) OK, so it's just StarWind Management console. Fine.

2) Please upgrade to V6 as 5.8 is outdated.

3) Please do 2) and let us know results (so we'd not hunt for something fixed a while ago).
jason.bashaw wrote:-are you evaluating SMI-S provider?
Not sure what you are asking (the SMI-S threw me).

-what starwind build are you using?
5.8.2060

-what starwind device type are you running?
deduplicated disk attached to iSCSI target

Re: Trouble connecting to iSCSI target

Posted: Wed Sep 19, 2012 6:10 pm
by jason.bashaw
Same result. This is the error I get in System Center:

Could not retrieve a certificate from the 10.20.0.2 server because of the error: The underlying connection was closed: An unexpected error occurred on a send.

Specify a valid server name and port.

ID: 20909
Details: An existing connection was forcibly closed by the remote host (0x80072746)

IP address and port are valid.

Re: Trouble connecting to iSCSI target

Posted: Thu Sep 20, 2012 6:56 pm
by Anatoly (staff)
May I ask you if you have got any AV software or FireWalls running?