Login Failed

scurtis22 · Tue Jul 12, 2005 12:10 am

Hello there.
I am trying to test a connection using an HP server to with a Qlogic HBA card to the StarWind iSCSI imagefile. It all goes well until I try to format the drive when installing the Windows 2003 OS. It appears that there is a certain number of connections that I am limited to, but am not sure if this is the problem.

Can someone let me know what the issue is here?

Thanks
Steve

23:59:41:812 (5b4) C[0x1116], IN_LOGIN: Event - LOGIN_ACCEPT.

23:59:41:812 (5b4) C[0x1116], LOGGED_IN: T5.

00:00:05:765 (30c) T[0x4a0081]: *ERROR* Skipping 4768 bytes.

00:00:05:765 (30c) C[0x1116], LOGGED_IN: *ERROR* 'recv' thread: recv failed 274a.

00:00:05:765 (5b4) S: iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0: 0 session(s) are opened, 1 more allowed.

Val (staff) · Tue Jul 12, 2005 12:04 pm

Hi,

What is the StarWind version?

Could you send me a more detailed log file from the StarWind Service (with LogLevel=3)?
Please send the file's archive directly to my email.

scurtis22 · Wed Jul 13, 2005 6:16 pm

It is version 2.6.1. I had a non-commercial version installed and uninstalled, also removing the registry key under local machine (not sure if there was another one that I should remove) and then installed the demo, since I was having problems with what appeared to be a limitation with licensing or connections.
It looks like from the logs that this is still the problem.
Please let me know your thoughts.
Thanks
Steve

18:02:57:218 (530) Params: <<< String param 'InitiatorName': received 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804', accepted 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804'

18:02:57:218 (530) Params: <<< String param 'TargetName': received 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0', accepted 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0'

18:02:57:218 (530) Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'

18:02:57:218 (530) Params: <<< Boolean param 'InitialR2T': received No, accepted 0

18:02:57:218 (530) Params: <<< Numeric param 'FirstBurstLength': received 131072, accepted 65536

18:02:57:218 (530) Params: <<< Boolean param 'DataPDUInOrder': received No, accepted 0

18:02:57:218 (530) Params: <<< Boolean param 'DataSequenceInOrder': received No, accepted 0

18:02:57:218 (530) Params: <<< Numeric param 'MaxRecvDataSegmentLength': received 65536, accepted 65536

18:02:57:218 (530) Params: Update OFMarkInt according to the value of OFMarker.

18:02:57:218 (530) Params: Update IFMarkInt according to the value of IFMarker.

18:02:57:218 (530) func: <<< iScsiParams::updateFromString

18:02:57:218 (530) func: >>> iScsiTask::startLoginPhase

18:02:57:218 (530) S: *ERROR* iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0: all of 1 allowed sessions are opened.

18:02:57:218 (530) S[0x2224]: *ERROR* No more sessions for allowed due to target 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0' restrictions.

18:02:57:218 (530) T[0x1000003]: *ERROR* Login request: failed while opening the device.

18:02:57:218 (530) func: <<< iScsiTask::startLoginPhase

18:02:57:218 (530) func: >>> iScsiTask::setState

18:02:57:218 (530) T[0x1000003]: setState 0x30.

18:02:57:218 (530) func: <<< iScsiTask::setState

18:02:57:218 (530) func: <<< iScsiTask::handleFirstLoginReq

18:02:57:218 (530) func: <<< iScsiTask::handlePdu

18:02:57:218 (530) func: <<< iScsiConnection::handlePdu

18:02:57:218 (530) func: <<< iScsiConnection::handleFirstLogin

18:02:57:218 (530) func: <<< iScsiConnection::receive

18:02:57:218 (530) func: >>> iScsiConnection::receive

18:02:57:218 (530) func: >>> iScsiConnection::recvData

18:02:57:218 (4e4) C[0x1114], IN_LOGIN: Send thread priority: 1

18:02:57:218 (31c) S[0x2224]: Session exec thread priority: 2

18:02:57:218 (31c) func: >>> iScsiSession::execute

18:02:57:218 (31c) S[0x2224]: Executing task: CmdSN 0, ITT 0x1000003.

18:02:57:218 (31c) func: >>> iScsiTask::execute

18:02:57:218 (31c) func: >>> iScsiTask::execLoginReq

18:02:57:218 (31c) func: >>> iScsiTask::setState

18:02:57:218 (31c) T[0x1000003]: setState 0x700.

18:02:57:218 (31c) func: <<< iScsiTask::setState

18:02:57:218 (31c) func: <<< iScsiTask::execLoginReq

18:02:57:218 (31c) func: <<< iScsiTask::execute

18:02:57:218 (31c) func: <<< iScsiSession::execute

18:02:57:218 (4e4) func: >>> iScsiConnection::send

18:02:57:218 (4e4) func: >>> iScsiTask::sendBufsCount

18:02:57:218 (4e4) func: <<< iScsiTask::sendBufsCount

18:02:57:218 (4e4) func: >>> iScsiTask::sendFillBufs

18:02:57:218 (4e4) T[0x1000003]: << PDU: OpCode 35, StatSN 0, ExpCmdSN 0, MaxCmdSN 0.

18:02:57:218 (4e4) func: <<< iScsiTask::sendFillBufs

18:02:57:218 (4e4) func: >>> iScsiTask::sendComplete

18:02:57:218 (4e4) func: >>> iScsiConnection::doTransition

18:02:57:218 (4e4) C[0x1114], IN_LOGIN: Event - LOGIN_REJECT.

18:02:57:218 (4e4) C[0x1114], FREE: T7.

18:02:57:218 (4e4) func: >>> iScsiConnection::initiateShutdown

18:02:57:218 (4e4) func: <<< iScsiConnection::initiateShutdown

18:02:57:218 (4e4) func: <<< iScsiConnection::doTransition

18:02:57:218 (4e4) func: >>> iScsiTask::setState

18:02:57:218 (4e4) T[0x1000003]: setState 0x1000.

18:02:57:218 (4e4) func: <<< iScsiTask::setState

18:02:57:218 (4e4) func: <<< iScsiTask::sendComplete

18:02:57:218 (4e4) func: >>> iScsiTaskList::freeCompleted

18:02:57:218 (4e4) func: <<< iScsiTaskList::freeCompleted

18:02:57:218 (4e4) func: <<< iScsiConnection::send

18:02:57:218 (4e4) C[0x1114], FREE: 'send' thread: logout response has been sent, exiting...

18:02:57:218 (530) func: <<< iScsiConnection::recvData

18:02:57:218 (530) func: <<< iScsiConnection::receive

18:02:57:218 (530) C[0x1114], FREE: 'recv' thread: stop command received (2), exiting...

18:02:57:218 (530) func: >>> iScsiConnection::waitForShutdownComplete

18:02:57:218 (530) func: <<< iScsiConnection::waitForShutdownComplete

18:02:57:218 (4e4) func: >>> iScsiConnection::initiateShutdown

18:02:57:218 (4e4) func: <<< iScsiConnection::initiateShutdown

18:02:57:218 (4e4) func: >>> iScsiConnection::waitForShutdownComplete

18:02:57:218 (4e4) C[0x1114], FREE: 'recv' thread: stopping...

18:02:57:218 (4e4) C[0x1114], FREE: 'recv' thread: stopped successfully.

18:02:57:218 (31c) func: >>> iScsiSession::RemoveConnection::execute

18:02:57:218 (31c) func: >>> iScsiSession::doRemoveConnection

18:02:57:218 (31c) func: >>> iScsiTaskList::abortTasks

18:02:57:218 (31c) func: <<< iScsiTaskList::abortTasks

18:02:57:218 (31c) func: >>> iScsiSession::removeConnection

18:02:57:218 (31c) func: <<< iScsiSession::removeConnection

18:02:57:218 (31c) func: >>> iScsiSession::initiateShutdown

18:02:57:218 (31c) S[0x2224]: Stopping 'execute' and all 'recv' and 'send' threads belonging to this session...

18:02:57:218 (31c) func: <<< iScsiSession::initiateShutdown

18:02:57:218 (31c) func: >>> iScsiServer::removeConnection

18:02:57:218 (31c) func: <<< iScsiServer::removeConnection

18:02:57:218 (31c) func: <<< iScsiSession::doRemoveConnection

18:02:57:218 (31c) func: <<< iScsiSession::RemoveConnection::execute

18:02:57:218 (31c) func: >>> iScsiSession::Command::execute

18:02:57:218 (31c) func: <<< iScsiSession::Command::execute

18:02:57:218 (31c) func: >>> iScsiSession::waitForShutdownComplete

18:02:57:218 (31c) func: >>> iScsiServer::removeSession

18:02:57:218 (31c) func: <<< iScsiServer::removeSession

18:02:57:218 (31c) S[0x2224]: RefCount==0. Deleting the session...

18:02:57:218 (31c) S[0x2224]: Session destructor called.

18:02:57:218 (31c) func: <<< iScsiSession::waitForShutdownComplete

18:02:57:218 (4e4) func: <<< iScsiConnection::waitForShutdownComplete

18:02:57:218 (4e4) C[0x1114], FREE: RefCount==0. Deleting the connection...

18:02:57:218 (4e4) C[0x1114], FREE: Connection destructor called.

18:03:00:218 (2f0) Srv: Accepted connection from 192.168.1.110:30388. id assigned - 4373

18:03:00:218 (2f0) func: >>> iScsiServer::addConnection

18:03:00:218 (2f0) func: <<< iScsiServer::addConnection

18:03:00:218 (2f0) func: >>> iScsiConnection::start

18:03:00:218 (2f0) func: >>> iScsiServer::removeConnection

18:03:00:218 (2f0) func: <<< iScsiServer::removeConnection

18:03:00:218 (2f0) func: >>> iScsiSession::addConnection

18:03:00:218 (2f0) func: <<< iScsiSession::addConnection

18:03:00:218 (2f0) func: >>> iScsiServer::addSession

18:03:00:218 (2f0) func: <<< iScsiServer::addSession

18:03:00:218 (2f0) func: >>> iScsiConnection::doTransition

18:03:00:218 (2f0) C[0x1115], FREE: Event - CONNECTED.

18:03:00:218 (2f0) C[0x1115], XPT_UP: T3.

18:03:00:218 (2f0) func: <<< iScsiConnection::doTransition

18:03:00:218 (2f0) func: >>> iScsiSession::start

18:03:00:218 (2f0) func: <<< iScsiSession::start

18:03:00:218 (2f0) func: <<< iScsiConnection::start

18:03:00:218 (648) C[0x1115], XPT_UP: Recv thread priority: 1

18:03:00:218 (648) func: >>> iScsiConnection::receive

18:03:00:218 (648) func: >>> iScsiConnection::recvData

18:03:00:218 (648) func: <<< iScsiConnection::recvData

18:03:00:218 (648) func: >>> iScsiConnection::handleFirstLogin

18:03:00:218 (648) C[0x1115], XPT_UP: Login request: ISID 0x0040210f0c07, TSIH 0x0000.

18:03:00:218 (648) func: >>> iScsiConnection::handlePdu

18:03:00:218 (648) C[0x1115], XPT_UP: >> PDU: Opcode 3, I: ITT 0x1100003, CmdSn 0, ExpStatSN 0; T: ExpCmdSN 0, MaxCmdSN 63.

18:03:00:218 (648) func: >>> iScsiTaskList::allocateTask

18:03:00:218 (648) func: <<< iScsiTaskList::allocateTask

18:03:00:218 (648) C[0x1115], XPT_UP: New task has been created (0): ITT 0x1100003.

18:03:00:218 (648) func: >>> iScsiTask::handlePdu

18:03:00:218 (648) func: >>> iScsiTask::handleFirstLoginReq

18:03:00:218 (648) func: >>> iScsiParams::allocateDefault

18:03:00:218 (648) func: <<< iScsiParams::allocateDefault

18:03:00:218 (648) func: >>> iScsiConnection::doTransition

18:03:00:218 (648) C[0x1115], XPT_UP: Event - LOGIN.

18:03:00:218 (648) C[0x1115], IN_LOGIN: T4.

18:03:00:218 (648) func: <<< iScsiConnection::doTransition

18:03:00:218 (648) func: >>> iScsiTask::recvLoginText

18:03:00:218 (648) func: >>> iScsiConnection::recvData

18:03:00:218 (648) func: <<< iScsiConnection::recvData

18:03:00:218 (648) func: <<< iScsiTask::recvLoginText

18:03:00:218 (648) func: >>> iScsiParams::updateFromString

18:03:00:218 (648) Params: <<< String param 'InitiatorName': received 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804', accepted 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804'

18:03:00:218 (648) Params: <<< String param 'TargetName': received 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0', accepted 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0'

18:03:00:218 (648) Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'

18:03:00:218 (648) Params: <<< Boolean param 'InitialR2T': received No, accepted 0

18:03:00:218 (648) Params: <<< Numeric param 'FirstBurstLength': received 131072, accepted 65536

18:03:00:218 (648) Params: <<< Boolean param 'DataPDUInOrder': received No, accepted 0

18:03:00:218 (648) Params: <<< Boolean param 'DataSequenceInOrder': received No, accepted 0

18:03:00:218 (648) Params: <<< Numeric param 'MaxRecvDataSegmentLength': received 65536, accepted 65536

18:03:00:218 (648) Params: Update OFMarkInt according to the value of OFMarker.

18:03:00:218 (648) Params: Update IFMarkInt according to the value of IFMarker.

18:03:00:218 (648) func: <<< iScsiParams::updateFromString

18:03:00:218 (648) func: >>> iScsiTask::startLoginPhase

18:03:00:218 (648) S: *ERROR* iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0: all of 1 allowed sessions are opened.

18:03:00:218 (648) S[0x2225]: *ERROR* No more sessions for allowed due to target 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0' restrictions.

18:03:00:218 (648) T[0x1100003]: *ERROR* Login request: failed while opening the device.

18:03:00:218 (648) func: <<< iScsiTask::startLoginPhase

18:03:00:218 (648) func: >>> iScsiTask::setState

18:03:00:218 (648) T[0x1100003]: setState 0x30.

18:03:00:218 (648) func: <<< iScsiTask::setState

18:03:00:218 (648) func: <<< iScsiTask::handleFirstLoginReq

18:03:00:218 (648) func: <<< iScsiTask::handlePdu

18:03:00:218 (648) func: <<< iScsiConnection::handlePdu

18:03:00:218 (648) func: <<< iScsiConnection::handleFirstLogin

18:03:00:218 (648) func: <<< iScsiConnection::receive

18:03:00:218 (648) func: >>> iScsiConnection::receive

18:03:00:218 (648) func: >>> iScsiConnection::recvData

18:03:00:218 (1b4) C[0x1115], IN_LOGIN: Send thread priority: 1

18:03:00:218 (2e0) S[0x2225]: Session exec thread priority: 2

18:03:00:218 (2e0) func: >>> iScsiSession::execute

18:03:00:218 (2e0) S[0x2225]: Executing task: CmdSN 0, ITT 0x1100003.

18:03:00:218 (2e0) func: >>> iScsiTask::execute

18:03:00:218 (2e0) func: >>> iScsiTask::execLoginReq

18:03:00:218 (2e0) func: >>> iScsiTask::setState

18:03:00:218 (2e0) T[0x1100003]: setState 0x700.

18:03:00:218 (2e0) func: <<< iScsiTask::setState

18:03:00:218 (2e0) func: <<< iScsiTask::execLoginReq

18:03:00:218 (2e0) func: <<< iScsiTask::execute

18:03:00:218 (2e0) func: <<< iScsiSession::execute

18:03:00:218 (1b4) func: >>> iScsiConnection::send

18:03:00:218 (1b4) func: >>> iScsiTask::sendBufsCount

18:03:00:218 (1b4) func: <<< iScsiTask::sendBufsCount

18:03:00:218 (1b4) func: >>> iScsiTask::sendFillBufs

18:03:00:218 (1b4) T[0x1100003]: << PDU: OpCode 35, StatSN 0, ExpCmdSN 0, MaxCmdSN 0.

18:03:00:218 (1b4) func: <<< iScsiTask::sendFillBufs

18:03:00:218 (1b4) func: >>> iScsiTask::sendComplete

18:03:00:218 (1b4) func: >>> iScsiConnection::doTransition

18:03:00:218 (1b4) C[0x1115], IN_LOGIN: Event - LOGIN_REJECT.

18:03:00:218 (1b4) C[0x1115], FREE: T7.

18:03:00:218 (1b4) func: >>> iScsiConnection::initiateShutdown

18:03:00:218 (1b4) func: <<< iScsiConnection::initiateShutdown

18:03:00:218 (1b4) func: <<< iScsiConnection::doTransition

18:03:00:218 (1b4) func: >>> iScsiTask::setState

18:03:00:218 (1b4) T[0x1100003]: setState 0x1000.

18:03:00:218 (1b4) func: <<< iScsiTask::setState

18:03:00:218 (1b4) func: <<< iScsiTask::sendComplete

18:03:00:218 (1b4) func: >>> iScsiTaskList::freeCompleted

18:03:00:218 (1b4) func: <<< iScsiTaskList::freeCompleted

18:03:00:218 (1b4) func: <<< iScsiConnection::send

18:03:00:218 (1b4) C[0x1115], FREE: 'send' thread: logout response has been sent, exiting...

18:03:00:218 (648) func: <<< iScsiConnection::recvData

18:03:00:218 (648) func: <<< iScsiConnection::receive

18:03:00:218 (648) C[0x1115], FREE: 'recv' thread: stop command received (2), exiting...

18:03:00:218 (648) func: >>> iScsiConnection::waitForShutdownComplete

18:03:00:218 (648) func: <<< iScsiConnection::waitForShutdownComplete

18:03:00:218 (1b4) func: >>> iScsiConnection::initiateShutdown

18:03:00:218 (1b4) func: <<< iScsiConnection::initiateShutdown

18:03:00:218 (1b4) func: >>> iScsiConnection::waitForShutdownComplete

18:03:00:218 (1b4) C[0x1115], FREE: 'recv' thread: stopping...

18:03:00:218 (1b4) C[0x1115], FREE: 'recv' thread: stopped successfully.

18:03:00:218 (2e0) func: >>> iScsiSession::RemoveConnection::execute

18:03:00:218 (2e0) func: >>> iScsiSession::doRemoveConnection

18:03:00:218 (2e0) func: >>> iScsiTaskList::abortTasks

18:03:00:218 (2e0) func: <<< iScsiTaskList::abortTasks

18:03:00:218 (2e0) func: >>> iScsiSession::removeConnection

18:03:00:218 (2e0) func: <<< iScsiSession::removeConnection

18:03:00:218 (2e0) func: >>> iScsiSession::initiateShutdown

18:03:00:218 (2e0) S[0x2225]: Stopping 'execute' and all 'recv' and 'send' threads belonging to this session...

18:03:00:234 (2e0) func: <<< iScsiSession::initiateShutdown

18:03:00:234 (2e0) func: >>> iScsiServer::removeConnection

18:03:00:234 (2e0) func: <<< iScsiServer::removeConnection

18:03:00:234 (2e0) func: <<< iScsiSession::doRemoveConnection

18:03:00:234 (2e0) func: <<< iScsiSession::RemoveConnection::execute

18:03:00:234 (2e0) func: >>> iScsiSession::Command::execute

18:03:00:234 (2e0) func: <<< iScsiSession::Command::execute

18:03:00:234 (2e0) func: >>> iScsiSession::waitForShutdownComplete

18:03:00:234 (2e0) func: >>> iScsiServer::removeSession

18:03:00:234 (2e0) func: <<< iScsiServer::removeSession

18:03:00:234 (2e0) S[0x2225]: RefCount==0. Deleting the session...

18:03:00:234 (2e0) S[0x2225]: Session destructor called.

18:03:00:234 (2e0) func: <<< iScsiSession::waitForShutdownComplete

18:03:00:234 (1b4) func: <<< iScsiConnection::waitForShutdownComplete

18:03:00:234 (1b4) C[0x1115], FREE: RefCount==0. Deleting the connection...

18:03:00:234 (1b4) C[0x1115], FREE: Connection destructor called.

18:03:01:796 (738) func: >>> ControlConnection::doList

18:03:01:796 (738) conf: Loaded 'list':

18:03:01:796 (738) conf: -what:"devices"

18:03:01:796 (738) func: >>> iScsiServer::list

18:03:01:796 (738) Srv: -rescan:'0'

18:03:01:796 (738) Srv: -what:'devices'

18:03:01:796 (738) func: >>> iScsiPlugin::getDeviceInfo

18:03:01:796 (738) Plugin: DevName: 'RamDrive0'

18:03:01:796 (738) Plugin: Param: 'size' = '16'

18:03:01:796 (738) Plugin: Param: 'format' = 'yes'

18:03:01:796 (738) Plugin: Param: 'clustered' = 'no'

18:03:01:796 (738) func: <<< iScsiPlugin::getDeviceInfo

18:03:01:796 (738) func: >>> iScsiPlugin::getDeviceInfo

18:03:01:796 (738) Plugin: DevName: 'ImageFile0'

18:03:01:796 (738) Plugin: Param: 'header' = '0'

18:03:01:796 (738) Plugin: Param: 'file' = 'D:\StarWind\images\boot1.img'

18:03:01:796 (738) Plugin: Param: 'buffering' = 'no'

18:03:01:796 (738) Plugin: Param: 'clustered' = 'no'

18:03:01:796 (738) Plugin: Param: 'asyncmode' = 'no'

18:03:01:796 (738) func: <<< iScsiPlugin::getDeviceInfo

18:03:01:796 (738) func: <<< iScsiServer::list

18:03:01:796 (738) func: <<< ControlConnection::doList

18:03:01:796 (738) func: >>> ControlConnection::doStatistics

18:03:01:796 (738) func: <<< ControlConnection::doStatistics

18:03:01:796 (738) func: >>> ControlConnection::doStatistics

18:03:01:812 (738) func: <<< ControlConnection::doStatistics

18:03:03:218 (2f0) Srv: Accepted connection from 192.168.1.110:30389. id assigned - 4374

18:03:03:218 (2f0) func: >>> iScsiServer::addConnection

18:03:03:218 (2f0) func: <<< iScsiServer::addConnection

18:03:03:218 (2f0) func: >>> iScsiConnection::start

18:03:03:218 (2f0) func: >>> iScsiServer::removeConnection

18:03:03:218 (2f0) func: <<< iScsiServer::removeConnection

18:03:03:218 (2f0) func: >>> iScsiSession::addConnection

18:03:03:218 (2f0) func: <<< iScsiSession::addConnection

18:03:03:218 (2f0) func: >>> iScsiServer::addSession

18:03:03:218 (2f0) func: <<< iScsiServer::addSession

18:03:03:218 (2f0) func: >>> iScsiConnection::doTransition

18:03:03:218 (2f0) C[0x1116], FREE: Event - CONNECTED.

18:03:03:218 (2f0) C[0x1116], XPT_UP: T3.

18:03:03:218 (2f0) func: <<< iScsiConnection::doTransition

18:03:03:218 (2f0) func: >>> iScsiSession::start

18:03:03:218 (2f0) func: <<< iScsiSession::start

18:03:03:218 (2f0) func: <<< iScsiConnection::start

18:03:03:218 (52c) C[0x1116], XPT_UP: Recv thread priority: 1

18:03:03:218 (52c) func: >>> iScsiConnection::receive

18:03:03:218 (52c) func: >>> iScsiConnection::recvData

18:03:03:218 (52c) func: <<< iScsiConnection::recvData

18:03:03:218 (52c) func: >>> iScsiConnection::handleFirstLogin

18:03:03:218 (52c) C[0x1116], XPT_UP: Login request: ISID 0x0040210f0c07, TSIH 0x0000.

18:03:03:218 (52c) func: >>> iScsiConnection::handlePdu

18:03:03:218 (52c) C[0x1116], XPT_UP: >> PDU: Opcode 3, I: ITT 0x1210003, CmdSn 0, ExpStatSN 0; T: ExpCmdSN 0, MaxCmdSN 63.

18:03:03:218 (52c) func: >>> iScsiTaskList::allocateTask

18:03:03:218 (52c) func: <<< iScsiTaskList::allocateTask

18:03:03:218 (52c) C[0x1116], XPT_UP: New task has been created (0): ITT 0x1210003.

18:03:03:218 (52c) func: >>> iScsiTask::handlePdu

18:03:03:218 (52c) func: >>> iScsiTask::handleFirstLoginReq

18:03:03:218 (52c) func: >>> iScsiParams::allocateDefault

18:03:03:218 (52c) func: <<< iScsiParams::allocateDefault

18:03:03:218 (52c) func: >>> iScsiConnection::doTransition

18:03:03:218 (52c) C[0x1116], XPT_UP: Event - LOGIN.

18:03:03:218 (52c) C[0x1116], IN_LOGIN: T4.

18:03:03:218 (52c) func: <<< iScsiConnection::doTransition

18:03:03:218 (52c) func: >>> iScsiTask::recvLoginText

18:03:03:218 (52c) func: >>> iScsiConnection::recvData

18:03:03:218 (52c) func: <<< iScsiConnection::recvData

18:03:03:218 (52c) func: <<< iScsiTask::recvLoginText

18:03:03:218 (52c) func: >>> iScsiParams::updateFromString

18:03:03:218 (52c) Params: <<< String param 'InitiatorName': received 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804', accepted 'iqn.2000-04.com.qlogic:qla4010.fs20521b01804'

18:03:03:218 (52c) Params: <<< String param 'TargetName': received 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0', accepted 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0'

18:03:03:218 (52c) Params: <<< Enum param 'SessionType': received 'Normal', accepted 'Normal'

18:03:03:218 (52c) Params: <<< Boolean param 'InitialR2T': received No, accepted 0

18:03:03:218 (52c) Params: <<< Numeric param 'FirstBurstLength': received 131072, accepted 65536

18:03:03:218 (52c) Params: <<< Boolean param 'DataPDUInOrder': received No, accepted 0

18:03:03:218 (52c) Params: <<< Boolean param 'DataSequenceInOrder': received No, accepted 0

18:03:03:218 (52c) Params: <<< Numeric param 'MaxRecvDataSegmentLength': received 65536, accepted 65536

18:03:03:218 (52c) Params: Update OFMarkInt according to the value of OFMarker.

18:03:03:218 (52c) Params: Update IFMarkInt according to the value of IFMarker.

18:03:03:218 (52c) func: <<< iScsiParams::updateFromString

18:03:03:218 (52c) func: >>> iScsiTask::startLoginPhase

18:03:03:218 (52c) S: *ERROR* iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0: all of 1 allowed sessions are opened.

18:03:03:218 (52c) S[0x2226]: *ERROR* No more sessions for allowed due to target 'iqn.2003-06.com.rocketdivision.starwind:beta-vm.imagefile.imagefile0' restrictions.

18:03:03:218 (52c) T[0x1210003]: *ERROR* Login request: failed while opening the device.

18:03:03:218 (52c) func: <<< iScsiTask::startLoginPhase

18:03:03:218 (52c) func: >>> iScsiTask::setState

18:03:03:218 (52c) T[0x1210003]: setState 0x30.

18:03:03:218 (52c) func: <<< iScsiTask::setState

18:03:03:218 (52c) func: <<< iScsiTask::handleFirstLoginReq

18:03:03:218 (52c) func: <<< iScsiTask::handlePdu

18:03:03:218 (52c) func: <<< iScsiConnection::handlePdu

18:03:03:218 (52c) func: <<< iScsiConnection::handleFirstLogin

18:03:03:218 (52c) func: <<< iScsiConnection::receive

18:03:03:218 (52c) func: >>> iScsiConnection::receive

18:03:03:218 (52c) func: >>> iScsiConnection::recvData

18:03:03:218 (7a0) C[0x1116], IN_LOGIN: Send thread priority: 1

18:03:03:218 (5b8) S[0x2226]: Session exec thread priority: 2

18:03:03:218 (5b8) func: >>> iScsiSession::execute

18:03:03:218 (5b8) S[0x2226]: Executing task: CmdSN 0, ITT 0x1210003.

18:03:03:218 (5b8) func: >>> iScsiTask::execute

18:03:03:218 (5b8) func: >>> iScsiTask::execLoginReq

18:03:03:218 (5b8) func: >>> iScsiTask::setState

18:03:03:218 (5b8) T[0x1210003]: setState 0x700.

18:03:03:218 (5b8) func: <<< iScsiTask::setState

18:03:03:218 (5b8) func: <<< iScsiTask::execLoginReq

18:03:03:218 (5b8) func: <<< iScsiTask::execute

18:03:03:218 (5b8) func: <<< iScsiSession::execute

18:03:03:218 (7a0) func: >>> iScsiConnection::send

18:03:03:218 (7a0) func: >>> iScsiTask::sendBufsCount

18:03:03:218 (7a0) func: <<< iScsiTask::sendBufsCount

18:03:03:218 (7a0) func: >>> iScsiTask::sendFillBufs

18:03:03:218 (7a0) T[0x1210003]: << PDU: OpCode 35, StatSN 0, ExpCmdSN 0, MaxCmdSN 0.

18:03:03:218 (7a0) func: <<< iScsiTask::sendFillBufs

18:03:03:218 (7a0) func: >>> iScsiTask::sendComplete

18:03:03:218 (7a0) func: >>> iScsiConnection::doTransition

18:03:03:218 (7a0) C[0x1116], IN_LOGIN: Event - LOGIN_REJECT.

18:03:03:218 (7a0) C[0x1116], FREE: T7.

18:03:03:218 (7a0) func: >>> iScsiConnection::initiateShutdown

18:03:03:218 (7a0) func: <<< iScsiConnection::initiateShutdown

18:03:03:218 (7a0) func: <<< iScsiConnection::doTransition

18:03:03:218 (7a0) func: >>> iScsiTask::setState

18:03:03:218 (7a0) T[0x1210003]: setState 0x1000.

18:03:03:218 (7a0) func: <<< iScsiTask::setState

18:03:03:218 (7a0) func: <<< iScsiTask::sendComplete

18:03:03:218 (7a0) func: >>> iScsiTaskList::freeCompleted

18:03:03:218 (7a0) func: <<< iScsiTaskList::freeCompleted

18:03:03:218 (7a0) func: <<< iScsiConnection::send

18:03:03:218 (7a0) C[0x1116], FREE: 'send' thread: logout response has been sent, exiting...

18:03:03:218 (52c) func: <<< iScsiConnection::recvData

18:03:03:218 (52c) func: <<< iScsiConnection::receive

18:03:03:218 (52c) C[0x1116], FREE: 'recv' thread: stop command received (2), exiting...

18:03:03:218 (52c) func: >>> iScsiConnection::waitForShutdownComplete

18:03:03:218 (52c) func: <<< iScsiConnection::waitForShutdownComplete

18:03:03:218 (7a0) func: >>> iScsiConnection::initiateShutdown

18:03:03:218 (7a0) func: <<< iScsiConnection::initiateShutdown

18:03:03:218 (7a0) func: >>> iScsiConnection::waitForShutdownComplete

18:03:03:218 (7a0) C[0x1116], FREE: 'recv' thread: stopping...

18:03:03:218 (7a0) C[0x1116], FREE: 'recv' thread: stopped successfully.

18:03:03:218 (5b8) func: >>> iScsiSession::RemoveConnection::execute

18:03:03:218 (5b8) func: >>> iScsiSession::doRemoveConnection

18:03:03:218 (5b8) func: >>> iScsiTaskList::abortTasks

18:03:03:218 (5b8) func: <<< iScsiTaskList::abortTasks

18:03:03:218 (5b8) func: >>> iScsiSession::removeConnection

18:03:03:218 (5b8) func: <<< iScsiSession::removeConnection

18:03:03:218 (5b8) func: >>> iScsiSession::initiateShutdown

18:03:03:218 (5b8) S[0x2226]: Stopping 'execute' and all 'recv' and 'send' threads belonging to this session...

18:03:03:218 (5b8) func: <<< iScsiSession::initiateShutdown

18:03:03:218 (5b8) func: >>> iScsiServer::removeConnection

18:03:03:218 (5b8) func: <<< iScsiServer::removeConnection

18:03:03:218 (5b8) func: <<< iScsiSession::doRemoveConnection

18:03:03:218 (5b8) func: <<< iScsiSession::RemoveConnection::execute

18:03:03:218 (5b8) func: >>> iScsiSession::Command::execute

18:03:03:218 (5b8) func: <<< iScsiSession::Command::execute

18:03:03:218 (5b8) func: >>> iScsiSession::waitForShutdownComplete

18:03:03:218 (5b8) func: >>> iScsiServer::removeSession

18:03:03:218 (5b8) func: <<< iScsiServer::removeSession

18:03:03:218 (5b8) S[0x2226]: RefCount==0. Deleting the session...

18:03:03:218 (5b8) S[0x2226]: Session destructor called.

18:03:03:218 (5b8) func: <<< iScsiSession::waitForShutdownComplete

18:03:03:218 (7a0) func: <<< iScsiConnection::waitForShutdownComplete

18:03:03:218 (7a0) C[0x1116], FREE: RefCount==0. Deleting the connection...

18:03:03:218 (7a0) C[0x1116], FREE: Connection destructor called.

18:03:03:859 (738) func: >>> ControlConnection::doShowlog

Val (staff) · Wed Jul 13, 2005 9:58 pm

Hi,

It seems the StarWind kept an old session opened for the target that prevented other login attempts.

Try to use '-clustered:yes' for the ImageFile target. This will allow several simultaneous connnections to the target.
I guess this should help to work around the issue.

Please let us know whether the settings solve the problem.