everything seems to be working except block device
jmacie...@gmail.com
2.6.17.7 (patched only with reiser4, see
http://people.msoe.edu/~maciejej/config.txt.gz for config) and
open-iscsi 654 for an initiator.
Everything builds, the modules load, the daemon starts, discovery
works, and I think the initiator connects to the target. See below.
Notice what I don't see---the SCSI driver reporting vendor, model, etc.
and a block device for the iSCSI target. I'm a noob when it comes to
iSCSI, so there's a high probability I'm doing something wrong.
gentoo # /etc/init.d/iscsid start
* Caching service dependencies ...
[ ok ]
* Loading iSCSI modules - scsi_transport_iscsi ...
[ ok ]
* Loading iSCSI modules - iscsi_tcp ...
[ ok ]
* Starting iSCSI initiator service ...
[ ok ]
gentoo # dmesg
SCSI subsystem initialized
Loading iSCSI transport class v1.1-654.
iscsi: registered transport (tcp)
gentoo # iscsiadm -m node
[e2d4b2] 192.168.0.10:3260,1
iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test
[d85b27] 192.168.10.37:3260,1
iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test
[159003] 192.168.0.10:3260,-1 <not specified>
gentoo # iscsiadm -m node -r e2d4b2 -l
gentoo # dmesg
SCSI subsystem initialized
Loading iSCSI transport class v1.1-654.
iscsi: registered transport (tcp)
scsi0 : iSCSI Initiator over TCP/IP
gentoo #
solaris # iscsitadm list target -v test
Target: test
iSCSI Name:
iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test
Connections: 1
Initiator:
iSCSI Name:
iqn.2006-08-localdomain.gentoo:0d599f0ec05c3bda8c3b8a68c32a1b47
Alias: gentoo
ACL list:
TPGT list:
LUN information:
LUN: 0
GUID: 010000d0b7205e3a00002a0044e93487
VID: SUN
PID: SOLARIS
Type: disk
Size: 1.0G
Status: online
solaris #
While I'm at it, is there anything I should know about using iSCSI
devices for dm-crypt or similar, or can I expect it to just work?
Mike Christie
> I'm running Solaris build 45 for a target and Gentoo with kernel
Is there a iscsi target that comes with open solaris? Is it open source?
> 2.6.17.7 (patched only with reiser4, see
> http://people.msoe.edu/~maciejej/config.txt.gz for config) and
> open-iscsi 654 for an initiator.
>
> Everything builds, the modules load, the daemon starts, discovery
> works, and I think the initiator connects to the target. See below.
> Notice what I don't see---the SCSI driver reporting vendor, model, etc.
> and a block device for the iSCSI target. I'm a noob when it comes to
> iSCSI, so there's a high probability I'm doing something wrong.
>
Could you run iscsid as "iscsid -d 8". This will give us some more
debugging output.
jmacie...@gmail.com
>
> Is there a iscsi target that comes with open solaris? Is it open source?
See http://www.opensolaris.org/os/project/iscsitgt/ for project info.
Code is available at
http://cvs.opensolaris.org/source/xref/on/usr/src/cmd/iscsi/
> Could you run iscsid as "iscsid -d 8". This will give us some more
> debugging output.
gentoo # iscsid -d 8 -f
iscsid: transport class version 1.1-654. iscsid version 1.1-654
iscsid: IPC socket is listening...
iscsid: in ctldev_open
iscsid: created NETLINK_ISCSI socket...
iscsid:
InitiatorName=iqn.2006-08-localdomain.gentoo:0d599f0ec05c3bda8c3b8a68c32a1b47
iscsid: InitiatorAlias=gentoo
iscsid:
InitiatorName=iqn.2006-08-localdomain.gentoo:0d599f0ec05c3bda8c3b8a68c32a1b47
iscsid: InitiatorAlias=gentoo
iscsid: in ktrans_list
iscsid: set utransport 0x51f660 for transport tcp
iscsid: synced 1 transport(s)
iscsid: iSCSI sync pid=27244 started
iscsid: reaped pid 27244, reap_count now 0
iscsid: poll result 1
iscsid: poll result 1
iscsid: poll result 1
iscsid: poll result 1
iscsid: updating defaults from '/etc/iscsid.conf'
iscsid: updated 'node.startup', 'manual' => 'manual'
iscsid: updated 'node.session.timeo.replacement_timeout', '120' =>
'120'
iscsid: updated 'node.session.err_timeo.abort_timeout', '10' => '10'
iscsid: updated 'node.session.err_timeo.reset_timeout', '30' => '30'
iscsid: updated 'node.session.iscsi.InitialR2T', 'No' => 'No'
iscsid: updated 'node.session.iscsi.ImmediateData', 'Yes' => 'Yes'
iscsid: updated 'node.session.iscsi.FirstBurstLength', '262144' =>
'262144'
iscsid: updated 'node.session.iscsi.MaxBurstLength', '16776192' =>
'16776192'
iscsid: updated 'node.session.iscsi.DefaultTime2Wait', '0' => '0'
iscsid: updated 'node.session.iscsi.DefaultTime2Retain', '0' => '0'
iscsid: updated 'node.session.iscsi.MaxConnections', '1' => '0'
iscsid: updated 'node.conn[0].iscsi.HeaderDigest', 'None,CRC32C' =>
'None'
iscsid: updated 'node.conn[0].iscsi.DataDigest', 'None' => 'None'
iscsid: updated 'node.conn[0].iscsi.MaxRecvDataSegmentLength', '131072'
=> '65536'
iscsid: searching for key
'192.168.0.10:3260#192.168.0.10:3260,1#iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test'
iscsid: in ktrans_list
iscsid: thread 2b3a88758fb8 schedule: delay 0 state 2
iscsid: no authentication configured...
iscsid: resolved 192.168.0.10 to 192.168.0.10
iscsid: set TCP recv window size to 524288, actually got 262142
iscsid: set TCP send window size to 524288, actually got 262142
iscsid: connecting to 192.168.0.10:3260
iscsid: event_type: 2 adding to the tail:
0x0x52a4d0:0x0x52a4d0:0x0x52a4f0:0x0x52e4d0 elem 0x0x52a4d0 length 32
iscsid: thread 2b3a88758fb8 schedule: delay 0 state 1
iscsid: thread 2b3a88732a18 schedule: delay 60 state 2
iscsid: exec thread 2b3a88758fb8 callback
iscsid: event_type: 2 removing from the head:
0x0x52a4d0:0x0x52a4f0:0x0x52a4f0:0x0x52e4d0 elem 0x0x52a4d0 length 32
iscsid: connected local port 59984 to 192.168.0.10:3260
iscsid: thread 2b3a88732a18 delete: state 0
iscsid: deleting a scheduled/waiting thread!
iscsid: in kcreate_session
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: created new iSCSI session 3
iscsid: in kcreate_conn
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: created new iSCSI connection 3:0
iscsid: in kbind_conn
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: bound iSCSI connection 3:0 to session 3
iscsid: sending login PDU with current stage 1, next stage 3, transit
0x80, isid 0x00023d000000 exp_statsn 0
iscsid: >
InitiatorName=iqn.2006-08-localdomain.gentoo:0d599f0ec05c3bda8c3b8a68c32a1b47
iscsid: > InitiatorAlias=gentoo
iscsid: >
TargetName=iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test
iscsid: > SessionType=Normal
iscsid: > HeaderDigest=None
iscsid: > DataDigest=None
iscsid: > DefaultTime2Wait=0
iscsid: > DefaultTime2Retain=0
iscsid: > IFMarker=No
iscsid: > OFMarker=No
iscsid: > ErrorRecoveryLevel=0
iscsid: > InitialR2T=No
iscsid: > ImmediateData=Yes
iscsid: > MaxBurstLength=16776192
iscsid: > FirstBurstLength=262144
iscsid: > MaxOutstandingR2T=1
iscsid: > MaxConnections=1
iscsid: > DataPDUInOrder=Yes
iscsid: > DataSequenceInOrder=Yes
iscsid: > MaxRecvDataSegmentLength=65536
iscsid: in ksend_pdu_begin
iscsid: send PDU began for hdr 48 bytes and data 508 bytes
iscsid: thread 2b3a88732a48 schedule: delay 60 state 2
iscsid: send_pdu timer added 15 secs
iscsid: in kwritev
iscsid: wrote 48 bytes of PDU header
iscsid: in kwritev
iscsid: wrote 508 bytes of PDU data
iscsid: in ksend_pdu_end
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: send PDU finished for conn 3:0
iscsid: thread removed
iscsid: poll result 1
iscsid: in ctldev_handle
iscsid: in nl_read
iscsid: message real length is 364 bytes, recv_handle 0x52e4e0
iscsid: in nlpayload_read
iscsid: event_type: 1 adding to the tail:
0x0x52a4d0:0x0x52a4d0:0x0x52a4f8:0x0x52e4d0 elem 0x0x52a4d0 length 40
iscsid: thread 2b3a88758fb8 schedule: delay 0 state 2
iscsid: exec thread 2b3a88758fb8 callback
iscsid: event_type: 1 removing from the head:
0x0x52a4d0:0x0x52a4f8:0x0x52a4f8:0x0x52e4d0 elem 0x0x52a4d0 length 40
iscsid: in krecv_pdu_begin
iscsid: recv PDU began, pdu handle 0x0x52e4e0
iscsid: in kread
iscsid: read 48 bytes of PDU header
iscsid: read 48 PDU header bytes, opcode 0x23, dlength 243, data
0x2b3a88730610, max 8192
iscsid: in kread
iscsid: read 243 bytes of PDU data
iscsid: finished reading login PDU, 48 hdr, 0 ah, 243 data, 3 pad
iscsid: login current stage 1, next stage 3, transit 0x80
iscsid: > TargetAlias=test
iscsid: > TargetPortalGroupTag=1
iscsid: > HeaderDigest=None
iscsid: > DataDigest=None
iscsid: > IFMarker=No
iscsid: > OFMarker=No
iscsid: > ErrorRecoveryLevel=0
iscsid: > InitialR2T=Yes
iscsid: > ImmediateData=Yes
iscsid: > MaxConnections=1
iscsid: > DataPDUInOrder=Yes
iscsid: > DataSequenceInOrder=Yes
iscsid: > MaxRecvDataSegmentLength=65536
iscsid: in krecv_pdu_end
iscsid: recv PDU finished for pdu handle 0x0x52e4e0
iscsid: thread 2b3a88732a48 delete: state 0
iscsid: deleting a scheduled/waiting thread!
iscsid: send_pdu timer removed
iscsid: login response status 0000
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 0 to:
iscsid: 65536
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 1 to:
iscsid: 65536
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 2 to:
iscsid: 0
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 3 to:
iscsid: 0
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 4 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 5 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 6 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 7 to:
iscsid: 262144
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 8 to:
iscsid: 16776192
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 9 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 10 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 11 to:
iscsid: 0
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 14 to:
iscsid: 2
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 15 to:
iscsid:
iqn.1986-03.com.sun:02:8d2ceb65-a6b4-ed9c-a4d8-a692e6e19c18.test
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 16 to:
iscsid: 1
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 17 to:
iscsid: 192.168.0.10
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 18 to:
iscsid: 3260
iscsid: in kset_param
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: set operational parameter 19 to:
iscsid: 120
iscsid: in kstart_conn
iscsid: in __kipc_call
iscsid: in kwritev
iscsid: in nlpayload_read
iscsid: in nlpayload_read
iscsid: scanning host3 using /sys/class/scsi_host/host3/scan
iscsid: scanning host3 from pid 27283
iscsid: connection3:0 is operational now
iscsid: thread removed
iscsid: write_mgmt_rsp: rsp to fd 7
iscsid: scanning host3 completed
iscsid: reaped pid 27283, reap_count now 0
iscsid: poll result 1
iscsid: in ctldev_handle
iscsid: in nl_read
iscsid: message real length is 120 bytes, recv_handle 0x52e4e0
iscsid: in nlpayload_read
iscsid: event_type: 1 adding to the tail:
0x0x52a4d0:0x0x52a4d0:0x0x52a4f8:0x0x52e4d0 elem 0x0x52a4d0 length 40
iscsid: thread 2b3a88758fb8 schedule: delay 0 state 2
iscsid: exec thread 2b3a88758fb8 callback
iscsid: event_type: 1 removing from the head:
0x0x52a4d0:0x0x52a4f8:0x0x52a4f8:0x0x52e4d0 elem 0x0x52a4d0 length 40
iscsid: in krecv_pdu_begin
iscsid: recv PDU began, pdu handle 0x0x52e4e0
iscsid: in kread
iscsid: read 48 bytes of PDU header
iscsid: read 48 PDU header bytes, opcode 0x60, dlength 0, data
0x2b3a88730610, max 8192
iscsid: in krecv_pdu_end
iscsid: recv PDU finished for pdu handle 0x0x52e4e0
iscsid: unsupported opcode 0x60
iscsid: thread removed
...
Mike Christie
> Mike Christie wrote:
>> Is there a iscsi target that comes with open solaris? Is it open source?
>
> See http://www.opensolaris.org/os/project/iscsitgt/ for project info.
>
Oh neat.
> Code is available at
> http://cvs.opensolaris.org/source/xref/on/usr/src/cmd/iscsi/
>
>> Could you run iscsid as "iscsid -d 8". This will give us some more
>> debugg
>
> iscsid: write_mgmt_rsp: rsp to fd 7
> iscsid: scanning host3 completed
It looks like everything went ok as far as the iscsi parts go. Are you
sure you have the luns exported on the target correctly?
>
> iscsid: in krecv_pdu_end
> iscsid: recv PDU finished for pdu handle 0x0x52e4e0
> iscsid: unsupported opcode 0x60
> iscsid: thread removed
>
It looks like we forgot to mask the opcode. Try the attached patch. I am
not sure it will fix the problem with finding devices. It probably will
not since we have already finished scanning at this point.
If it still does not work, then could you send me a ethereal trace so we
can see what is going on with the scanning?
jmacie...@gmail.com
>
> It looks like everything went ok as far as the iscsi parts go. Are you
> sure you have the luns exported on the target correctly?
>
guide- http://www.opensolaris.org/os/project/iscsitgt/getstarted/.
Also, I'm able to connect to the target with a different Solaris box,
and I get a SCSI device that I'm able to partition, slice, newfs,
mount, and transfer files to/from.
>
> It looks like we forgot to mask the opcode. Try the attached patch. I am
> not sure it will fix the problem with finding devices. It probably will
> not since we have already finished scanning at this point.
>
http://people.msoe.edu/~maciejej/iscsi/iscsid_log.txt.gz
> If it still does not work, then could you send me a ethereal trace so we
> can see what is going on with the scanning?
>
http://people.msoe.edu/~maciejej/iscsi/iscsi_login_capture.gz
I think I should also mention that sometimes I see the following:
KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at
net/netlink/af_netlink.c (146)
Mike Christie
> KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at
> net/netlink/af_netlink.c (146)
>
Are you starting and stoping the iscsi service or killing and restarting
iscsid? If so we know about those and it should not affect scanning.
Tomasz Chmielewski
I stop iscsi service with a script (/etc/init.d/open-iscsi), but saw it
several times.
r654 + 2.6.16-xen kernel.
--
Tomasz Chmielewski
http://wpkg.org
jmacie...@gmail.com
kill the daemon or stop the service.
Albert Pauw
I have seen it for as long as I remember, nothing to worry about.
But maybe it's getting time to resolve this.
jmacie...@gmail.com
also capture a successful login from the Solaris initiator.
Mike Christie
> Have you made any progress on this issue? If it might help, I could
> also capture a successful login from the Solaris initiator.
>
The iscsi bits are fine. It looks like a problem in the linux scsi
layer. For normal IO, we will retry a Unit Attention with those asc and
ascq values, but for scanning and some other IOs we do not.
If the iscsi host is host9, then if you did this to retry the scan from
userspace manually:
echo - - - > /sys/class/scsi_host/host9/scan
it should find your disks.
I am still working on a linux scsi layer patch to do the retry.
jmacie...@gmail.com
fdisk, mkfs, and mount, I'm getting I /O errors.
SCSI subsystem initialized
Loading iSCSI transport class v1.1-654.
iscsi: registered transport (tcp)
scsi0 : iSCSI Initiator over TCP/IP
Vendor: SUN Model: SOLARIS Rev: 1
Type: Direct-Access ANSI SCSI revision: 05
SCSI device sda: 2097152 512-byte hdwr sectors (1074 MB)
sda: Write Protect is off
sda: Mode Sense: 03 16 00 00
sda: got wrong page
sda: assuming drive cache: write through
SCSI device sda: 2097152 512-byte hdwr sectors (1074 MB)
sda: Write Protect is off
sda: Mode Sense: 03 16 00 00
sda: got wrong page
sda: assuming drive cache: write through
sda: sda1
sda1: <solaris: [s0] sda5 [s2] sda6 >
sd 0:0:0:0: Attached scsi disk sda
SCSI device sda: 2097152 512-byte hdwr sectors (1074 MB)
sda: Write Protect is off
sda: Mode Sense: 03 16 00 00
sda: got wrong page
sda: assuming drive cache: write through
sda: sda1
SCSI device sda: 2097152 512-byte hdwr sectors (1074 MB)
sda: Write Protect is off
sda: Mode Sense: 03 16 00 00
sda: got wrong page
sda: assuming drive cache: write through
sda: sda1
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
sd 0:0:0:0: SCSI error: return code = 0x20000
end_request: I/O error, dev sda, sector 239
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
sd 0:0:0:0: SCSI error: return code = 0x20000
end_request: I/O error, dev sda, sector 247
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
sd 0:0:0:0: SCSI error: return code = 0x20000
end_request: I/O error, dev sda, sector 255
connection0:0: iscsi: detected conn error (1012)
connection0:0: iscsi: detected conn error (1012)
...
Mike Christie
> Thank you. Rescanning was indeed all that was required. Now after
> fdisk, mkfs, and mount, I'm getting I /O errors.
>
Ah the joys of being the first person to try a initiator and target combo :)
> connection0:0: iscsi: detected conn error (1012)
Either the initiator or target is messing up the r2tsn. Could you send a
ethereal trace again? And if you have time, could you send me a open
solaris for dummies link so I can try to install the target and test
against it?
jmacie...@gmail.com
same as an ethereal capture. I also logged the output of iscsid in case
it might help. Oh, and I'm on version 682.
http://people.msoe.edu/~maciejej/iscsi/iscsi_write_failure.tcpdump.gz
http://people.msoe.edu/~maciejej/iscsi/iscsid_write_failure_messages.txt.gz
All I did was make an ext2 filesystem, mount it, dd 100 blocks from
/dev/zero, sync, copy a tarball of open-iscsi 682, and try to sync
again. The second sync hung.
If you want to try Solaris, you'll probably want the semi-official
"Solaris Express Community Release" available as a few CDs or one DVD
(the second URL below):
http://javashoplm.sun.com/ECom/docs/Welcome.jsp?StoreId=7&PartDetailId=Sol-Express_b46-x86-SP-G-B&TransactionId=try
http://javashoplm.sun.com/ECom/docs/Welcome.jsp?StoreId=7&PartDetailId=Sol-Express_b46-DVD-x86-SP-G-B&TransactionId=try
Anyone with reasonable *NIX experience should be able to get through
the installation. The dependencies are ugly, so you might be best off
installing everything. Then just follow:
http://www.opensolaris.org/os/project/iscsitgt/getstarted/
If you don't have the iscsitadm command, look on your install CDs/DVD
for iscsi packages and add them with pkgadd.