The following warnings occurred:
Warning [2] count(): Parameter must be an array or an object that implements Countable - Line: 807 - File: showthread.php PHP 7.3.15 (Linux)
File Line Function
/showthread.php 807 errorHandler->error





Post Reply 
 
Thread Rating:
  • 0 Vote(s) - 0 Average
  • 1
  • 2
  • 3
  • 4
  • 5
[SOLVED] iSCSI read errors during iPXE boot
2019-02-13, 23:19 (This post was last modified: 2019-02-17 21:10 by tlum.)
Post: #1
[SOLVED] iSCSI read errors during iPXE boot
EDIT: Substantially updated 2019-02-16 to include additional troubleshooting information.

I've had iPXE and iSCSI environments in place for years now, but for the first time I'm attempting to do an iSCSI boot and the iPXE is having a problem with the conversation with the iSCSI target.

The storage server
Code:
CentOS Linux release 7.6.1810 (Core)
Linux san1srvp01.********.net 3.10.0-957.5.1.el7.x86_64 #1 SMP Fri Feb 1 14:54:57 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux
zfs-0.7.12-1.el7_6.x86_64


The backing block instance
Code:
Disk /dev/zpool1/jane: 8422 MB, 8422687232 bytes, 16450561 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk label type: dos
Disk identifier: 0xa9a554b4

           Device Boot      Start         End      Blocks   Id  System
/dev/zpool1/jane1              63       80324       40131   12  Compaq diagnostics
/dev/zpool1/jane2   *       80325    16434494     8177085    7  HPFS/NTFS/exFAT


The backing fileio instance
Code:
Disk /zpool1/nas1/Media/c0d0.img: 8422 MB, 8422686720 bytes, 16450560 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk label type: dos
Disk identifier: 0xa9a554b4

                      Device Boot      Start         End      Blocks   Id  System
/zpool1/nas1/Media/c0d0.img1              63       80324       40131   12  Compaq diagnostics
/zpool1/nas1/Media/c0d0.img2   *       80325    16434494     8177085    7  HPFS/NTFS/exFAT


Simplified iSCSI Target configuration. This is an example of block using ZFS zvol, and I've also tried fileio which behaves no differently.
Code:
{
  "fabric_modules": [
    {
      "discovery_enable_auth": true,
      "discovery_password": "********************************",
      "discovery_userid": "san1srvp01",
      "name": "iscsi"
    }
  ],
  "storage_objects": [
    {
      "alua_tpgs": [
        {
          "alua_access_state": 0,
          "alua_access_status": 0,
          "alua_access_type": 3,
          "alua_support_active_nonoptimized": 1,
          "alua_support_active_optimized": 1,
          "alua_support_offline": 1,
          "alua_support_standby": 1,
          "alua_support_transitioning": 1,
          "alua_support_unavailable": 1,
          "alua_write_metadata": 0,
          "implicit_trans_secs": 0,
          "name": "default_tg_pt_gp",
          "nonop_delay_msecs": 100,
          "preferred": 0,
          "tg_pt_gp_id": 0,
          "trans_delay_msecs": 0
        }
      ],
      "attributes": {
        "block_size": 512,
        "emulate_3pc": 1,
        "emulate_caw": 1,
        "emulate_dpo": 1,
        "emulate_fua_read": 1,
        "emulate_fua_write": 1,
        "emulate_model_alias": 1,
        "emulate_rest_reord": 0,
        "emulate_tas": 1,
        "emulate_tpu": 0,
        "emulate_tpws": 0,
        "emulate_ua_intlck_ctrl": 0,
        "emulate_write_cache": 0,
        "enforce_pr_isids": 1,
        "force_pr_aptpl": 0,
        "is_nonrot": 1,
        "max_unmap_block_desc_count": 1,
        "max_unmap_lba_count": 262144,
        "max_write_same_len": 65535,
        "optimal_sectors": 32768,
        "pi_prot_format": 0,
        "pi_prot_type": 0,
        "queue_depth": 128,
        "unmap_granularity": 16,
        "unmap_granularity_alignment": 0,
        "unmap_zeroes_data": 0
      },
      "dev": "/dev/zpool1/jane",
      "name": "jane",
      "plugin": "block",
      "readonly": false,
      "write_back": false,
      "wwn": "8688850f-7200-48a0-ad32-0f4f9397a836"
    }
  ],
  "targets": [
    {
      "fabric": "iscsi",
      "tpgs": [
        {
          "attributes": {
            "authentication": 0,
            "cache_dynamic_acls": 0,
            "default_cmdsn_depth": 64,
            "default_erl": 0,
            "demo_mode_discovery": 1,
            "demo_mode_write_protect": 1,
            "fabric_prot_type": 0,
            "generate_node_acls": 0,
            "login_timeout": 15,
            "netif_timeout": 2,
            "prod_mode_write_protect": 0,
            "t10_pi": 0,
            "tpg_enabled_sendtargets": 1
          },
          "enable": true,
          "luns": [
            {
              "alias": "414d07d6b4",
              "alua_tg_pt_gp_name": "default_tg_pt_gp",
              "index": 2,
              "storage_object": "/backstores/block/jane"
            }
          ],
          "node_acls": [
            {
              "attributes": {
                "dataout_timeout": 3,
                "dataout_timeout_retries": 5,
                "default_erl": 0,
                "nopin_response_timeout": 30,
                "nopin_timeout": 15,
                "random_datain_pdu_offsets": 0,
                "random_datain_seq_offsets": 0,
                "random_r2t_offsets": 0
              },
              "chap_mutual_password": "****************",
              "chap_mutual_userid": "san1srvp01",
              "chap_password": "****************",
              "chap_userid": "jane",
              "mapped_luns": [
                {
                  "alias": "c8ce872be3",
                  "index": 2,
                  "tpg_lun": 2,
                  "write_protect": false
                }
              ],
              "node_wwn": "iqn.1999-10.net.********:jane"
            }
          ],
          "parameters": {
            "AuthMethod": "CHAP,None",
            "DataDigest": "CRC32C,None",
            "DataPDUInOrder": "Yes",
            "DataSequenceInOrder": "Yes",
            "DefaultTime2Retain": "20",
            "DefaultTime2Wait": "2",
            "ErrorRecoveryLevel": "0",
            "FirstBurstLength": "65536",
            "HeaderDigest": "CRC32C,None",
            "IFMarkInt": "2048~65535",
            "IFMarker": "No",
            "ImmediateData": "Yes",
            "InitialR2T": "Yes",
            "MaxBurstLength": "262144",
            "MaxConnections": "1",
            "MaxOutstandingR2T": "1",
            "MaxRecvDataSegmentLength": "8192",
            "MaxXmitDataSegmentLength": "262144",
            "OFMarkInt": "2048~65535",
            "OFMarker": "No",
            "TargetAlias": "LIO Target"
          },
          "portals": [
            {
              "ip_address": "192.168.40.1",
              "iser": false,
              "offload": false,
              "port": 3260
            }
          ],
          "tag": 1
        }
      ],
      "wwn": "iqn.1999-10.net.********:san1srvp01"
    }
  ]
}


The PXE/iPXE/TFTP/HTTP server
Code:
CentOS release 6.10 (Final)
Linux sy1srvp01.********.net 2.6.32-754.10.1.el6.i686 #1 SMP Tue Jan 15 17:33:10 UTC 2019 i686 i686 i386 GNU/Linux
tftp-0.49-8.el6.i686


The iPXE implementation will first hand off to scripts matching host name, uuid, or mac in that order. This is the individual iPXE boot script for this mac mac-0007e90feaf5.ipxe
Code:
set username jane
set password ****************
set reverse-username san1srvp01
set reverse-password ****************
set initiator-iqn iqn.1999-10.net.********:jane
sanboot iscsi:192.168.40.1::::iqn.1999-10.net.********:san1srvp01


The initiator
Code:
Compaq ML370 (Generation 0)
BIOS P17 (12/18/2002)
Processor 866/133 Mhz with 256k Cache
RAM 1 GB
Intel Boot Agent GE v1.2.22


The PXE -> iPXE chain load
Code:
PXE 2.1 Build 084 (WfM 2.0), RPL V1.25

PX->EB: PXE! at 9CC2:0070, entry point at 9CC2:0106
            UNDI code segment 9CC2:0000, data segment 969B:0000 (602-628kB)
            UNDI device is PCI 00:06.0, type DIX+802.3
            602kB free base memory after PXE unload
            
iPXE 1.0.0+ -- Open Source Network Boot Firmware -- http://ipxe.org
Features: DNS HTTP iSCSI TFTP AoE ELF MBOOT PXE bzImage Menu PXEXT


I've used a network trace to follow the iPXE sanboot iSCSI boot process. From a high level it is:

  1. Login Command (CHAP)
  2. Test Unit Ready
  3. Read Capacity(10)
  4. Read(10) <- Failure

First, the Read Capacity(10) return an unexpected value of 63 for LBA, instead of 16450560. It then attempts a Read(10) at LBA 64 which predictably fails with Logical Block Address Out Of Range. Testing indicates this is caused by specific interaction between iPXE and LIO, but the exact cause is unknown.

Read Capacity(10) - Request
Code:
Frame 27: 114 bytes on wire (912 bits), 114 bytes captured (912 bits)
Ethernet II, Src: Intel_0f:ea:f5 (00:07:e9:0f:ea:f5), Dst: SuperMic_6c:a9:82 (00:25:90:6c:a9:82)
Internet Protocol Version 4, Src: 192.168.4.13, Dst: 192.168.40.1
Transmission Control Protocol, Src Port: cifs (3020), Dst Port: iscsi-target (3260), Seq: 773, Ack: 637, Len: 48
iSCSI (SCSI Command)
Flags: 0xc1, F, R, Attr: Simple
SCSI CDB Read Capacity(10)
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [Response in: 29]
    Opcode: Read Capacity(10) (0x25)
    Control: 0x00

Read Capacity(10) - Response
Code:
Frame 29: 74 bytes on wire (592 bits), 74 bytes captured (592 bits)
Ethernet II, Src: SuperMic_6c:a9:82 (00:25:90:6c:a9:82), Dst: Intel_0f:ea:f5 (00:07:e9:0f:ea:f5)
Internet Protocol Version 4, Src: 192.168.40.1, Dst: 192.168.4.13
Transmission Control Protocol, Src Port: iscsi-target (3260), Dst Port: cifs (3020), Seq: 685, Ack: 821, Len: 8
[2 Reassembled TCP Segments (56 bytes): #28(48), #29(8)]
iSCSI (SCSI Data In)
SCSI Payload (Read Capacity(10) Response Data)
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [SBC Opcode: Read Capacity(10) (0x25)]
    [Request in: 27]
    [Response in: 29]
    LBA: 63 (0 MB)
    Block size in bytes: 512
SCSI Response (Read Capacity(10))
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [SBC Opcode: Read Capacity(10) (0x25)]
    [Request in: 27]
    [Time from request: 0.000252000 seconds]
    [Status: Good (0x00)]

Read(10) - Request
Code:
Frame 32: 114 bytes on wire (912 bits), 114 bytes captured (912 bits)
Ethernet II, Src: Intel_0f:ea:f5 (00:07:e9:0f:ea:f5), Dst: SuperMic_6c:a9:82 (00:25:90:6c:a9:82)
Internet Protocol Version 4, Src: 192.168.4.13, Dst: 192.168.40.1
Transmission Control Protocol, Src Port: cifs (3020), Dst Port: iscsi-target (3260), Seq: 821, Ack: 693, Len: 48
iSCSI (SCSI Command)
Flags: 0xc1, F, R, Attr: Simple
SCSI CDB Read(10)
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [Response in: 33]
    Opcode: Read(10) (0x28)
    Flags: 0x00
    Logical Block Address (LBA): 64
    ...0 0000 = Group: 0x00
    Transfer Length: 4
    Control: 0x00

Read(10) - Response
Code:
Frame 33: 214 bytes on wire (1712 bits), 214 bytes captured (1712 bits)
Ethernet II, Src: SuperMic_6c:a9:82 (00:25:90:6c:a9:82), Dst: Intel_0f:ea:f5 (00:07:e9:0f:ea:f5)
Internet Protocol Version 4, Src: 192.168.40.1, Dst: 192.168.4.13
Transmission Control Protocol, Src Port: iscsi-target (3260), Dst Port: cifs (3020), Seq: 693, Ack: 869, Len: 148
iSCSI (SCSI Response)
Flags: 0x80
SCSI: SNS Info
    [LUN: 0x0000]
    .111 0000 = SNS Error Type: Current Error (0x70)
    Valid: 112
    0... .... = Filemark: False
    .0.. .... = EOM: False
    ..0. .... = ILI: False
    .... 0101 = Sense Key: Illegal Request (0x5)
    Sense Info: 0x00000000
    Additional Sense Length: 10
    Command-Specific Information: 00000000
    Additional Sense Code+Qualifier: Logical Block Address Out Of Range (0x2100)
    Field Replaceable Unit Code: 0x00
    0... .... = SKSV: False
    .000 0000 0000 0000 0000 0000 = Sense Key Specific: 0x000000


The iPXE response to the console
Code:
Could not open SAN device: Input/output error (http://ipxe.org/1d704039
Could not boot image: Input/output error (http://ipxe.org/1d704039

The message logged on the iSCSI target
Code:
Feb 13 09:17:41 san1srvp01 kernel: cmd exceeds last lba 64 (lba 64, sectors 4)


Testing and Troubleshooting
  • Identical behavior is observed when attempting to boot a VM using this iSCSI LUN, ruling out the physical machine and its network card.
  • The iSCSI device behaves correctly when mounted using the native Linux initiator, and the device was initially populated over an iSCSI mount using dd to copy the image file to it.
  • I created a custom build of iPXE that forces Read Capacity(16) and Read(16), to no avail.
  • I have found one documented instance of similar behavior which was determined to be caused by the operational parameters supplied (or not) during the Login stage, in that case. In response, I created a custom build with the same parameters and parameter values as those observed during a working mount using the native Linux initiator, to no avail.
  • I have tried moving the fileio backing store image from ZFS to an xfs volume, to no avail.
  • I have tried the iPXE sanboot with the block device initialized with zeros, to no avail. This suggests the problem is not related to partitions or block device content.

  • Can anyone attest to having a working setup equivalent to this?
  • Does anyone know of definite problems with this setup?
  • Does anyone know what would cause LIO to behave in this way?
  • And the hardest question of all, does anyone know how to fix it?

-TIA
Find all posts by this user
Quote this message in a reply
Post Reply 


Messages In This Thread
[SOLVED] iSCSI read errors during iPXE boot - tlum - 2019-02-13 23:19



User(s) browsing this thread: 2 Guest(s)