"iSCSI PDU timed out" error trying to connect to LIO targets

[Martin]

Hi,

I'm trying to login to a linux-iscsi.org target. I issue the
following:

iscsiadm -m node -T iqn.2001-09.net.ketsds:keat.storage.fast3 -p
10.1.206.2 -l


and after a long pause get the following error:

iscsiadm: initiator reported error (11 - iSCSI PDU timed out)


Any ideas how to diagnose?

Target is CentOS 5.2 (kernel 2.6.18-92.1.13.e15) running LIO
2.9.0.384. I have been able to use the same targets from an MS
Windows 2008 initiator.

Initiator is CentOS 5.2 (not sure the kernel) with open-iscsi
2.0-868. Discovery (iscsiadm -m discovery -t sendtargets -p
10.1.206.2) worked fine.


thanks

Martin

[Mike Christie]

Are you using CHAP or does the target have some sort of initiator access
list?

Is there anything in /var/log/messages about a login error (and
initiator dropping a pdu)? Is there anything in /var/log/messages from
iscsid?

Could you run iscsid with debugging by hand:

iscsid -d 8

and send the output.

[Martin]

> and send the output.- Hide quoted text -
>
> - Show quoted text -

Thanks for the quick response!


1) I am not using CHAP. That is, the target supports CHAP but I did
not define any users/passwords and I was able to connect from another
initiator without specifying any authentication info.

2) LIO does require me to specify the initiators allowed to use each
target. As far as I can tell I've configured that properly...

3) This is what I find in /var/log/messages around the time of an
iscsid login attempt:

Oct 20 12:39:15 ed3492-xen kernel: scsi5 : iSCSI Initiator over TCP/IP
Oct 20 12:39:15 ed3492-xen kernel: iscsi: dropping ctask with itt 0x0
Oct 20 12:39:15 ed3492-xen iscsid: session [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260] already
running.
Oct 20 12:39:33 ed3492-xen kernel: iscsi: dropping ctask with itt 0x0
Oct 20 12:40:08 ed3492-xen last message repeated 2 times


4) Here is the output from iscsid:

iscsiadm: Max file limits 1024 1024

iscsiadm: exec_node_op: : node [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260]
iscsiadm: searching iqn.2001-09.net.ketsds:keat.storage.fast1

iscsiadm: found 10.1.206.2,3260,1

iscsiadm: iface iter found default.
iscsiadm: updated 'node.name', '' => 'iqn.
2001-09.net.ketsds:keat.storage.fast1'
iscsiadm: updated 'node.tpgt', '-1' => '1'
iscsiadm: updated 'node.startup', 'manual' => 'automatic'
iscsiadm: updated 'iface.hwaddress', 'default' => 'default'
iscsiadm: updated 'iface.iscsi_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.net_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.transport_name', 'tcp' => 'tcp'
iscsiadm: updated 'node.discovery_address', '' => '10.1.206.2'
iscsiadm: updated 'node.discovery_port', '0' => '3260'
iscsiadm: updated 'node.discovery_type', 'static' => 'send_targets'
iscsiadm: updated 'node.session.initial_cmdsn', '0' => '0'
iscsiadm: updated 'node.session.initial_login_retry_max', '4' => '4'
iscsiadm: updated 'node.session.cmds_max', '128' => '128'
iscsiadm: updated 'node.session.queue_depth', '32' => '32'
iscsiadm: updated 'node.session.auth.authmethod', 'None' => 'None'
iscsiadm: updated 'node.session.timeo.replacement_timeout', '120' =>
'120'
iscsiadm: updated 'node.session.err_timeo.abort_timeout', '15' => '15'
iscsiadm: updated 'node.session.err_timeo.lu_reset_timeout', '30' =>
'30'
iscsiadm: updated 'node.session.err_timeo.host_reset_timeout', '60' =>
'60'
iscsiadm: updated 'node.session.iscsi.FastAbort', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.InitialR2T', 'No' => 'No'
iscsiadm: updated 'node.session.iscsi.ImmediateData', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.FirstBurstLength', '262144' =>
'262144'
iscsiadm: updated 'node.session.iscsi.MaxBurstLength', '16776192' =>
'16776192'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Retain', '0' => '0'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Wait', '2' => '2'
iscsiadm: updated 'node.session.iscsi.MaxConnections', '1' => '1'
iscsiadm: updated 'node.session.iscsi.MaxOutstandingR2T', '1' => '1'
iscsiadm: updated 'node.session.iscsi.ERL', '0' => '0'
iscsiadm: updated 'node.conn[0].address', '' => '10.1.206.2'
iscsiadm: updated 'node.conn[0].port', '3260' => '3260'
iscsiadm: updated 'node.conn[0].startup', 'manual' => 'manual'
iscsiadm: updated 'node.conn[0].tcp.window_size', '524288' => '524288'
iscsiadm: updated 'node.conn[0].tcp.type_of_service', '0' => '0'
iscsiadm: updated 'node.conn[0].timeo.logout_timeout', '15' => '15'
iscsiadm: updated 'node.conn[0].timeo.login_timeout', '30' => '15'
iscsiadm: updated 'node.conn[0].timeo.auth_timeout', '45' => '45'
iscsiadm: updated 'node.conn[0].timeo.noop_out_interval', '5' => '5'
iscsiadm: updated 'node.conn[0].timeo.noop_out_timeout', '5' => '5'
iscsiadm: updated 'node.conn[0].iscsi.MaxRecvDataSegmentLength',
'131072' => '131072'
iscsiadm: updated 'node.conn[0].iscsi.HeaderDigest', 'None,CRC32C' =>
'None,CRC32C'
iscsiadm: updated 'node.conn[0].iscsi.IFMarker', 'No' => 'No'
iscsiadm: updated 'node.conn[0].iscsi.OFMarker', 'No' => 'No'
iscsiadm: match session [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][ ,,]
iscsiadm: to [iqn.
2001-09.net.ketsds:keat.storage.fast1,10.1.206.2,3260][default
tcp,default,]
iscsiadm: searching iqn.2001-09.net.ketsds:keat.storage.fast2

iscsiadm: found 10.1.206.2,3260,1

iscsiadm: iface iter found default.
iscsiadm: updated 'node.name', '' => 'iqn.
2001-09.net.ketsds:keat.storage.fast2'
iscsiadm: updated 'node.tpgt', '-1' => '1'
iscsiadm: updated 'node.startup', 'manual' => 'automatic'
iscsiadm: updated 'iface.hwaddress', 'default' => 'default'
iscsiadm: updated 'iface.iscsi_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.net_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.transport_name', 'tcp' => 'tcp'
iscsiadm: updated 'node.discovery_address', '' => '10.1.206.2'
iscsiadm: updated 'node.discovery_port', '0' => '3260'
iscsiadm: updated 'node.discovery_type', 'static' => 'send_targets'
iscsiadm: updated 'node.session.initial_cmdsn', '0' => '0'
iscsiadm: updated 'node.session.initial_login_retry_max', '4' => '4'
iscsiadm: updated 'node.session.cmds_max', '128' => '128'
iscsiadm: updated 'node.session.queue_depth', '32' => '32'
iscsiadm: updated 'node.session.auth.authmethod', 'None' => 'None'
iscsiadm: updated 'node.session.timeo.replacement_timeout', '120' =>
'120'
iscsiadm: updated 'node.session.err_timeo.abort_timeout', '15' => '15'
iscsiadm: updated 'node.session.err_timeo.lu_reset_timeout', '30' =>
'30'
iscsiadm: updated 'node.session.err_timeo.host_reset_timeout', '60' =>
'60'
iscsiadm: updated 'node.session.iscsi.FastAbort', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.InitialR2T', 'No' => 'No'
iscsiadm: updated 'node.session.iscsi.ImmediateData', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.FirstBurstLength', '262144' =>
'262144'
iscsiadm: updated 'node.session.iscsi.MaxBurstLength', '16776192' =>
'16776192'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Retain', '0' => '0'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Wait', '2' => '2'
iscsiadm: updated 'node.session.iscsi.MaxConnections', '1' => '1'
iscsiadm: updated 'node.session.iscsi.MaxOutstandingR2T', '1' => '1'
iscsiadm: updated 'node.session.iscsi.ERL', '0' => '0'
iscsiadm: updated 'node.conn[0].address', '' => '10.1.206.2'
iscsiadm: updated 'node.conn[0].port', '3260' => '3260'
iscsiadm: updated 'node.conn[0].startup', 'manual' => 'manual'
iscsiadm: updated 'node.conn[0].tcp.window_size', '524288' => '524288'
iscsiadm: updated 'node.conn[0].tcp.type_of_service', '0' => '0'
iscsiadm: updated 'node.conn[0].timeo.logout_timeout', '15' => '15'
iscsiadm: updated 'node.conn[0].timeo.login_timeout', '30' => '15'
iscsiadm: updated 'node.conn[0].timeo.auth_timeout', '45' => '45'
iscsiadm: updated 'node.conn[0].timeo.noop_out_interval', '5' => '5'
iscsiadm: updated 'node.conn[0].timeo.noop_out_timeout', '5' => '5'
iscsiadm: updated 'node.conn[0].iscsi.MaxRecvDataSegmentLength',
'131072' => '131072'
iscsiadm: updated 'node.conn[0].iscsi.HeaderDigest', 'None,CRC32C' =>
'None,CRC32C'
iscsiadm: updated 'node.conn[0].iscsi.IFMarker', 'No' => 'No'
iscsiadm: updated 'node.conn[0].iscsi.OFMarker', 'No' => 'No'
iscsiadm: match session [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][ ,,]
iscsiadm: to [iqn.
2001-09.net.ketsds:keat.storage.fast2,10.1.206.2,3260][default
tcp,default,]
iscsiadm: searching iqn.2001-09.net.ketsds:keat.storage.fast3

iscsiadm: found 10.1.206.2,3260,1

iscsiadm: iface iter found default.
iscsiadm: updated 'node.name', '' => 'iqn.
2001-09.net.ketsds:keat.storage.fast3'
iscsiadm: updated 'node.tpgt', '-1' => '1'
iscsiadm: updated 'node.startup', 'manual' => 'automatic'
iscsiadm: updated 'iface.hwaddress', 'default' => 'default'
iscsiadm: updated 'iface.iscsi_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.net_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.transport_name', 'tcp' => 'tcp'
iscsiadm: updated 'node.discovery_address', '' => '10.1.206.2'
iscsiadm: updated 'node.discovery_port', '0' => '3260'
iscsiadm: updated 'node.discovery_type', 'static' => 'send_targets'
iscsiadm: updated 'node.session.initial_cmdsn', '0' => '0'
iscsiadm: updated 'node.session.initial_login_retry_max', '4' => '4'
iscsiadm: updated 'node.session.cmds_max', '128' => '128'
iscsiadm: updated 'node.session.queue_depth', '32' => '32'
iscsiadm: updated 'node.session.auth.authmethod', 'None' => 'None'
iscsiadm: updated 'node.session.timeo.replacement_timeout', '120' =>
'120'
iscsiadm: updated 'node.session.err_timeo.abort_timeout', '15' => '15'
iscsiadm: updated 'node.session.err_timeo.lu_reset_timeout', '30' =>
'30'
iscsiadm: updated 'node.session.err_timeo.host_reset_timeout', '60' =>
'60'
iscsiadm: updated 'node.session.iscsi.FastAbort', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.InitialR2T', 'No' => 'No'
iscsiadm: updated 'node.session.iscsi.ImmediateData', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.FirstBurstLength', '262144' =>
'262144'
iscsiadm: updated 'node.session.iscsi.MaxBurstLength', '16776192' =>
'16776192'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Retain', '0' => '0'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Wait', '2' => '2'
iscsiadm: updated 'node.session.iscsi.MaxConnections', '1' => '1'
iscsiadm: updated 'node.session.iscsi.MaxOutstandingR2T', '1' => '1'
iscsiadm: updated 'node.session.iscsi.ERL', '0' => '0'
iscsiadm: updated 'node.conn[0].address', '' => '10.1.206.2'
iscsiadm: updated 'node.conn[0].port', '3260' => '3260'
iscsiadm: updated 'node.conn[0].startup', 'manual' => 'manual'
iscsiadm: updated 'node.conn[0].tcp.window_size', '524288' => '524288'
iscsiadm: updated 'node.conn[0].tcp.type_of_service', '0' => '0'
iscsiadm: updated 'node.conn[0].timeo.logout_timeout', '15' => '15'
iscsiadm: updated 'node.conn[0].timeo.login_timeout', '30' => '15'
iscsiadm: updated 'node.conn[0].timeo.auth_timeout', '45' => '45'
iscsiadm: updated 'node.conn[0].timeo.noop_out_interval', '5' => '5'
iscsiadm: updated 'node.conn[0].timeo.noop_out_timeout', '5' => '5'
iscsiadm: updated 'node.conn[0].iscsi.MaxRecvDataSegmentLength',
'131072' => '131072'
iscsiadm: updated 'node.conn[0].iscsi.HeaderDigest', 'None,CRC32C' =>
'None,CRC32C'
iscsiadm: updated 'node.conn[0].iscsi.IFMarker', 'No' => 'No'
iscsiadm: updated 'node.conn[0].iscsi.OFMarker', 'No' => 'No'
iscsiadm: match session [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][ ,,]
iscsiadm: to [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][default
tcp,default,]
iscsiadm: found 10.1.206.2,3260

iscsiadm: updated 'node.name', '' => 'iqn.
2001-09.net.ketsds:keat.storage.fast3'
iscsiadm: updated 'node.tpgt', '-1' => '-1'
iscsiadm: updated 'node.startup', 'manual' => 'automatic'
iscsiadm: updated 'iface.hwaddress', 'default' => 'default'
iscsiadm: updated 'iface.iscsi_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.net_ifacename', 'default' => 'default'
iscsiadm: updated 'iface.transport_name', 'tcp' => 'tcp'
iscsiadm: updated 'node.discovery_port', '0' => '0'
iscsiadm: updated 'node.discovery_type', 'static' => 'static'
iscsiadm: updated 'node.session.initial_cmdsn', '0' => '0'
iscsiadm: updated 'node.session.initial_login_retry_max', '4' => '4'
iscsiadm: updated 'node.session.cmds_max', '128' => '128'
iscsiadm: updated 'node.session.queue_depth', '32' => '32'
iscsiadm: updated 'node.session.auth.authmethod', 'None' => 'None'
iscsiadm: updated 'node.session.timeo.replacement_timeout', '120' =>
'120'
iscsiadm: updated 'node.session.err_timeo.abort_timeout', '15' => '15'
iscsiadm: updated 'node.session.err_timeo.lu_reset_timeout', '30' =>
'30'
iscsiadm: updated 'node.session.err_timeo.host_reset_timeout', '60' =>
'60'
iscsiadm: updated 'node.session.iscsi.FastAbort', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.InitialR2T', 'No' => 'No'
iscsiadm: updated 'node.session.iscsi.ImmediateData', 'Yes' => 'Yes'
iscsiadm: updated 'node.session.iscsi.FirstBurstLength', '262144' =>
'262144'
iscsiadm: updated 'node.session.iscsi.MaxBurstLength', '16776192' =>
'16776192'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Retain', '0' => '0'
iscsiadm: updated 'node.session.iscsi.DefaultTime2Wait', '2' => '2'
iscsiadm: updated 'node.session.iscsi.MaxConnections', '1' => '1'
iscsiadm: updated 'node.session.iscsi.MaxOutstandingR2T', '1' => '1'
iscsiadm: updated 'node.session.iscsi.ERL', '0' => '0'
iscsiadm: updated 'node.conn[0].address', '' => '10.1.206.2'
iscsiadm: updated 'node.conn[0].port', '3260' => '3260'
iscsiadm: updated 'node.conn[0].startup', 'manual' => 'manual'
iscsiadm: updated 'node.conn[0].tcp.window_size', '524288' => '524288'
iscsiadm: updated 'node.conn[0].tcp.type_of_service', '0' => '0'
iscsiadm: updated 'node.conn[0].timeo.logout_timeout', '15' => '15'
iscsiadm: updated 'node.conn[0].timeo.login_timeout', '30' => '15'
iscsiadm: updated 'node.conn[0].timeo.auth_timeout', '45' => '45'
iscsiadm: updated 'node.conn[0].timeo.noop_out_interval', '5' => '5'
iscsiadm: updated 'node.conn[0].timeo.noop_out_timeout', '5' => '5'
iscsiadm: updated 'node.conn[0].iscsi.MaxRecvDataSegmentLength',
'131072' => '131072'
iscsiadm: updated 'node.conn[0].iscsi.HeaderDigest', 'None,CRC32C' =>
'None,CRC32C'
iscsiadm: updated 'node.conn[0].iscsi.IFMarker', 'No' => 'No'
iscsiadm: updated 'node.conn[0].iscsi.OFMarker', 'No' => 'No'
iscsiadm: match session [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][ ,,]
iscsiadm: to [iqn.
2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260][default
tcp,default,]
iscsiadm: Could not login to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]:

iscsiadm: initiator reported error (11 - iSCSI PDU timed out)

iscsiadm: Could not login to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]:
iscsiadm: initiator reported error (15 - already exists)
Logging in to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]
Logging in to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]


thanks!

Martin

[Mike Christie]

Hmmm, maybe two problems.

> Oct 20 12:39:15 ed3492-xen kernel: scsi5 : iSCSI Initiator over TCP/IP
> Oct 20 12:39:15 ed3492-xen kernel: iscsi: dropping ctask with itt 0x0

This is really weird. It would normally only happen if we raced during
scsi eh processing, but at this point we should not be able to run scsi
eh processing. We might be getting a bad tag from the target or we might
have sent the target a bad tag.

What arch are you using? Is it a 64 bit one? Are you doing 64 bit
kernels and 32 bit userspace by any chance?

Are you using the kernel modules from Centos's kernel and the tools from
open-iscsi.org's open-iscsi 2.0-868 tarball? Or are you using the
iscsi-initiator-utils from Centos and the kernel modules from Cento's?
If you are using a tarball from open-iscsi.org did you do a make and
make isnstall? Did you install Centos's iscsi-initiator-utils then also
install the open-iscsi.org tarball tools.

> Oct 20 12:39:15 ed3492-xen iscsid: session [iqn.
> 2001-09.net.ketsds:keat.storage.fast3,10.1.206.2,3260] already
> running.

This and this:

> iscsiadm: Could not login to [iface: default, target: iqn.
> 2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]:
> iscsiadm: initiator reported error (11 - iSCSI PDU timed out)
> iscsiadm: Could not login to [iface: default, target: iqn.
> 2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]:
> iscsiadm: initiator reported error (15 - already exists)
> Logging in to [iface: default, target: iqn.
> 2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]
> Logging in to [iface: default, target: iqn.
> 2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]
>

is a little strange too. Some how you got multiple records with the same
values. There is only one target and one portal right? Have you recently
upgraded tools down graded?

You might want to do a "whereis iscsid" and "whereis iscsiadm" and
"rpm -q iscsi-initiator-utils".

Could you also run

iscsiadm -m node -P 1

and send the output

[Martin]

> and send the output- Hide quoted text -

>
> - Show quoted text -

It's all 64-bit as far as I can tell. I should tell you that I've
installed the xen bits on this "client" system as well.

I installed the open-iscsi bits from the CentOS repository (yum
install iscsi-initiator-utils)

There are three targets set up on my target host, all via the same
portal and port.

whereis says

iscsid: /sbin/iscsid
iscsiadm: /sbin/iscsiadm

rpm says

iscsi-initiator-utils-6.2.0.868-0.7.el5


isicsiadm -m node -P 1 says

Target: iqn.2001-09.net.ketsds:keat.storage.fast1
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast2
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast3
Portal: 10.1.206.2:3260,1
Iface Name: default
Iface Name: default


the third target is the one that I try to attach to...



thanks!

Martin

[Mike Christie]

Let's try to start from scratch, because the above should not happen.

Do

rm -f -r /var/lib/iscsi/*

Then redo discovery

iscsiadm -m discovery -t st ..... -l -P 1

(send this outpout)

Then do

iscsiadm -m node -P 1

(send this too).

[Martin]

> (send this too).- Hide quoted text -

>
> - Show quoted text -

Ok, I did

iscsiadm -m discovery -t st -p <my_ip> -l -P 1

STDOUT received

Target: iqn.2001-09.net.ketsds:keat.storage.fast1
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast2
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast3
Portal: 10.1.206.2:3260,1
Iface Name: default

Logging in to [iface: default, target: iqn.

2001-09.net.ketsds:keat.storage.fast1, portal: 10.1.206.2,3260]

Logging in to [iface: default, target: iqn.

2001-09.net.ketsds:keat.storage.fast2, portal: 10.1.206.2,3260]

Logging in to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]

STDERR received

iscsiadm: Could not login to [iface: default, target: iqn.

2001-09.net.ketsds:keat.storage.fast1, portal: 10.1.206.2,3260]:

iscsiadm: initiator reported error (11 - iSCSI PDU timed out)
iscsiadm: Could not login to [iface: default, target: iqn.

2001-09.net.ketsds:keat.storage.fast2, portal: 10.1.206.2,3260]:

iscsiadm: initiator reported error (11 - iSCSI PDU timed out)
iscsiadm: Could not login to [iface: default, target: iqn.
2001-09.net.ketsds:keat.storage.fast3, portal: 10.1.206.2,3260]:

iscsiadm: initiator reported error (11 - iSCSI PDU timed out)

Then I ran iscsiadm -m node -P 1

STDOUT received

Target: iqn.2001-09.net.ketsds:keat.storage.fast1
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast2
Portal: 10.1.206.2:3260,1
Iface Name: default
Target: iqn.2001-09.net.ketsds:keat.storage.fast3
Portal: 10.1.206.2:3260,1
Iface Name: default

STDERR received nothing



thanks!

Martin

[Mike Christie]

Martin wrote:
>
> Target: iqn.2001-09.net.ketsds:keat.storage.fast1
> Portal: 10.1.206.2:3260,1
> Iface Name: default
> Target: iqn.2001-09.net.ketsds:keat.storage.fast2
> Portal: 10.1.206.2:3260,1
> Iface Name: default
> Target: iqn.2001-09.net.ketsds:keat.storage.fast3
> Portal: 10.1.206.2:3260,1
> Iface Name: default
>

Ok it looks like we fixed the problem where we got duplicate records and
we got a already running error.

For the pdu timed out problem, I think we need a ethereal/wrireshark
trace so we can see why the target is sending us the wrong task tag. Do
you know how to run this? In centos5 I believe you have to use ethereal
(I do not think we picked up the renamed wireshark). Just run that on
the initiator box, when you run the "iscsiadm -m node -l". When that
fails with timed out errors, stop ethereal and send the trace.

[Martin]

Ok, I posted the trace to the group file area:

http://groups.google.com/group/open-iscsi/web/iscsi_adm_capture_22_oct_08_11_59


Thanks!

Martin

[Nicholas A. Bellinger]

Greetings Mike and Martin,

I just saw this thread this afternoon and decided to have a closer look
at RFC-3720 wrt your "pdu timed out problem", which has to do with what
fields of Login Response are considered "invalid" when a login fails
(for whatever reason) and a Status-Class of non zero is returned to the
iSCSI Initiator. From the RFC:

10.13.5. Status-Class and Status-Detail

<SNIP>

The status classes are as follows:

0 - Success - indicates that the iSCSI target successfully
received, understood, and accepted the request. The numbering
fields (StatSN, ExpCmdSN, MaxCmdSN) are only valid if
Status-Class is 0.

I had previously thought that Initiator Task Tag was also part of this
list for *ONLY* being valid when Status-Class is 0 (which is why you are
seeing it set to zero during login response failures), but as it is most
definately *NOT* correct according to RFC-3720, I went ahead and made
LIO-Target properly set Initiator Task Tag in Login Responses with
non-zero Status-Class.

Here is the commit that has been tested with v3.0:

http://git.kernel.org/?p=linux/kernel/git/nab/lio-core-2.6.git;a=commit;h=23280e4252c447735c3dd810d0b936f34c6f06a7

It has also been backed ported to v2.9-STABLE as r402.

Thanks!

--nab

Please make sure to include me on the thread if you run into any other
strangeness. :-)

> >

[Mike Christie]

Nicholas A. Bellinger wrote:
> Here is the commit that has been tested with v3.0:
>
> http://git.kernel.org/?p=linux/kernel/git/nab/lio-core-2.6.git;a=commit;h=23280e4252c447735c3dd810d0b936f34c6f06a7
>
> It has also been backed ported to v2.9-STABLE as r402.
>
> Thanks!
>
> --nab
>
> Please make sure to include me on the thread if you run into any other
> strangeness. :-)
>

I was wondering where you were :) Thanks a lot Nicholas!

[Martin]

Going to LIO 2.9 r403 - and fixing a typo in my LIO config file -
fixed this for me.

thanks

Martin

On Oct 30, 11:31 am, Mike Christie <micha...@cs.wisc.edu> wrote:
> Nicholas A. Bellinger wrote:
> > Here is the commit that has been tested with v3.0:
>

> >http://git.kernel.org/?p=linux/kernel/git/nab/lio-core-2.6.git;a=comm...