#66 Problem statement: iSCSI target failure

9.0.0.1
open
nobody
None
1
2014-08-28
2013-01-03
Asiris
No

Conditions:
- NAS4Free 9.1.0.1 revision 531 (or/and FreeNAS 0.7.2 behaves the same way)
- iSCSI target: istgt
- the DVD-ROM target created with istgt
- the iSCSI initiator creates the session with istgt target
- the iSCSI initiator claims the MaxRecvDataSegmentLength=8192 while
the session parameter negotiation stage
- the iSCSI initiator issues the SET MODE(10) SCSI command with
allocation length 0xFFF0 bytes
- the istgt immideately aborts the TCP connection (sends FIN)
- the istgt logfile contains the messages:
freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ERROR data_alloc_len(8192) too small
freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ERROR LU2: lu_dvd_execute() failed
freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ERROR lu_execute() failed
freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ERROR iscsi_op_scsi() failed

If the iSCSI initiator claims the MaxRecvDataSegmentLength=65536, the problem disappears.
But the small iSCSI segments is not acceptable at all for some iSCSI initiators (e.g. embedded
systems with limited amount of memory).

Related

Bugs: #66

Discussion

  • Daisuke Aoyama
    Daisuke Aoyama
    2013-01-03

    Please write complete log of NAS4Free 9.1.0.1.531.
    Your log seems not NAS4Free r531.

    or please write complete version of your server and istgt version by type from console or SSH:

    # istgt -V
    

    Thanks

     
  • Asiris
    Asiris
    2013-01-03

      Jan 3 10:58:06 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk0 LU1 (192.168.120.35:3260,1), ISID=801834567890, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:07 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801b34567890, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:16 freenas istgt[1365]: Login(discovery) from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on (192.168.120.35:3260,1), ISID=801c34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:16 freenas istgt[1365]: istgt_iscsi.c:2678:istgt_iscsi_op_logout: ***WARNING*** CmdSN(271140) might have dropped 
      Jan 3 10:58:16 freenas istgt[1365]: Logout(discovery) from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on (192.168.120.35:3260,1), ISID=801c34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:4921:worker: ***ERROR*** iscsi_execute() failed on iqn.2007-09.jp.ne.peach.istgt:disk1,t,0x0001(iqn.2006-01.com.disc-soft:vdas847:ata,i,0x801b34567890) 
      Jan 3 10:59:17 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801d34567890, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:17 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801d34567890, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:18 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801e34567890, TSIH=3, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:4921:worker: ***ERROR*** iscsi_execute() failed on iqn.2007-09.jp.ne.peach.istgt:disk1,t,0x0001(iqn.2006-01.com.disc-soft:vdas847:ata,i,0x801e34567890) 
      Jan 3 10:59:31 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801f34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:31 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801f34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:32 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=802034567890, TSIH=5, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed
    

    istgt version 0.5
    istgt extra version 20121123

    From: Daisuke Aoyama
    Sent: Thursday, January 03, 2013 4:07 PM
    To: [nas4free:bugs]
    Subject: [nas4free:bugs] #66 Problem statement: iSCSI target failure

    Please write complete log of NAS4Free 9.1.0.1.531.
    Your log seems not NAS4Free r531.

    or please write complete version of your server and istgt version by type from console or SSH:

    istgt -V

    Thanks


    [bugs:#66] Problem statement: iSCSI target failure

    Status: open
    Created: Thu Jan 03, 2013 12:48 PM UTC by Asiris
    Last Updated: Thu Jan 03, 2013 12:48 PM UTC
    Owner: nobody

    Conditions:
    - NAS4Free 9.1.0.1 revision 531 (or/and FreeNAS 0.7.2 behaves the same way)
    - iSCSI target: istgt
    - the DVD-ROM target created with istgt
    - the iSCSI initiator creates the session with istgt target
    - the iSCSI initiator claims the MaxRecvDataSegmentLength=8192 while
    the session parameter negotiation stage
    - the iSCSI initiator issues the SET MODE(10) SCSI command with
    allocation length 0xFFF0 bytes
    - the istgt immideately aborts the TCP connection (sends FIN)
    - the istgt logfile contains the messages:
    freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ERROR data_alloc_len(8192) too small
    freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ERROR LU2: lu_dvd_execute() failed
    freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ERROR lu_execute() failed
    freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ERROR iscsi_op_scsi() failed

    If the iSCSI initiator claims the MaxRecvDataSegmentLength=65536, the problem disappears.
    But the small iSCSI segments is not acceptable at all for some iSCSI initiators (e.g. embedded
    systems with limited amount of memory).


    Sent from sourceforge.net because you indicated interest in https://sourceforge.net/p/nas4free/bugs/66/

    To unsubscribe from further messages, please visit https://sourceforge.net/auth/prefs/

     

    Related

    Bugs: #66

  • Asiris
    Asiris
    2013-01-03

      Jan 3 10:58:06 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk0 LU1 (192.168.120.35:3260,1), ISID=801834567890, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:07 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801b34567890, TSIH=1, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:16 freenas istgt[1365]: Login(discovery) from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on (192.168.120.35:3260,1), ISID=801c34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:58:16 freenas istgt[1365]: istgt_iscsi.c:2678:istgt_iscsi_op_logout: ***WARNING*** CmdSN(271140) might have dropped 
      Jan 3 10:58:16 freenas istgt[1365]: Logout(discovery) from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on (192.168.120.35:3260,1), ISID=801c34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed 
      Jan 3 10:59:06 freenas istgt[1365]: istgt_iscsi.c:4921:worker: ***ERROR*** iscsi_execute() failed on iqn.2007-09.jp.ne.peach.istgt:disk1,t,0x0001(iqn.2006-01.com.disc-soft:vdas847:ata,i,0x801b34567890) 
      Jan 3 10:59:17 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801d34567890, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:17 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801d34567890, TSIH=2, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:18 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801e34567890, TSIH=3, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed 
      Jan 3 10:59:19 freenas istgt[1365]: istgt_iscsi.c:4921:worker: ***ERROR*** iscsi_execute() failed on iqn.2007-09.jp.ne.peach.istgt:disk1,t,0x0001(iqn.2006-01.com.disc-soft:vdas847:ata,i,0x801e34567890) 
      Jan 3 10:59:31 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801f34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:31 freenas istgt[1365]: Logout from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=801f34567890, TSIH=4, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:32 freenas istgt[1365]: Login from iqn.2006-01.com.disc-soft:vdas847:ata (192.168.120.8) on iqn.2007-09.jp.ne.peach.istgt:disk1 LU2 (192.168.120.35:3260,1), ISID=802034567890, TSIH=5, CID=1, HeaderDigest=off, DataDigest=off 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ***ERROR*** data_alloc_len(8192) too small 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ***ERROR*** LU2: lu_dvd_execute() failed 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ***ERROR*** lu_execute() failed 
      Jan 3 10:59:33 freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ***ERROR*** iscsi_op_scsi() failed
    

    istgt version 0.5

    From: Daisuke Aoyama
    Sent: Thursday, January 03, 2013 4:07 PM
    To: [nas4free:bugs]
    Subject: [nas4free:bugs] #66 Problem statement: iSCSI target failure

    Please write complete log of NAS4Free 9.1.0.1.531.
    Your log seems not NAS4Free r531.

    or please write complete version of your server and istgt version by type from console or SSH:

    istgt -V

    Thanks


    [bugs:#66] Problem statement: iSCSI target failure

    Status: open
    Created: Thu Jan 03, 2013 12:48 PM UTC by Asiris
    Last Updated: Thu Jan 03, 2013 12:48 PM UTC
    Owner: nobody

    Conditions:
    - NAS4Free 9.1.0.1 revision 531 (or/and FreeNAS 0.7.2 behaves the same way)
    - iSCSI target: istgt
    - the DVD-ROM target created with istgt
    - the iSCSI initiator creates the session with istgt target
    - the iSCSI initiator claims the MaxRecvDataSegmentLength=8192 while
    the session parameter negotiation stage
    - the iSCSI initiator issues the SET MODE(10) SCSI command with
    allocation length 0xFFF0 bytes
    - the istgt immideately aborts the TCP connection (sends FIN)
    - the istgt logfile contains the messages:
    freenas istgt[1365]: istgt_lu_dvd.c:3339:istgt_lu_dvd_execute: ERROR data_alloc_len(8192) too small
    freenas istgt[1365]: istgt_lu.c:2283:istgt_lu_execute: ERROR LU2: lu_dvd_execute() failed
    freenas istgt[1365]: istgt_iscsi.c:3118:istgt_iscsi_op_scsi: ERROR lu_execute() failed
    freenas istgt[1365]: istgt_iscsi.c:4400:istgt_iscsi_execute: ERROR iscsi_op_scsi() failed

    If the iSCSI initiator claims the MaxRecvDataSegmentLength=65536, the problem disappears.
    But the small iSCSI segments is not acceptable at all for some iSCSI initiators (e.g. embedded
    systems with limited amount of memory).


    Sent from sourceforge.net because you indicated interest in https://sourceforge.net/p/nas4free/bugs/66/

    To unsubscribe from further messages, please visit https://sourceforge.net/auth/prefs/

     

    Related

    Bugs: #66