open-iscsi/targetcli-fb

Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576

Opened this issue · 1 comments

Hi,

I have enabled a FILIO backing store and I have mounted it from a Win2016 Server. I do get lots of output in dmesg when doing something heavy like a chkdsk -r (surface scan). Are these messages harmless or do they indicate a problem that I need to sort out?

There are no errors reported in Windows, and as far as I can tell the storage works fine with no corruptions.

# System

OS: Alpine Linux 3.16
Kernel: 5.15.57
Targetcli: 2.1.54-r1

# dmesg

[65095.963669] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65095.964074] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65095.985581] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 950272 for SAM Opcode: 0x2f
[65100.964521] target_cmd_size_check: 11557 callbacks suppressed
[65100.964523] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.964979] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.965386] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 950272 for SAM Opcode: 0x2f
[65100.965783] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.966176] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.966543] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.966981] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 950272 for SAM Opcode: 0x2f
[65100.967355] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.967699] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65100.968045] TARGET_CORE[iSCSI]: Expected Transfer Length: 0 does not match SCSI CDB Length: 1048576 for SAM Opcode: 0x2f
[65105.968019] target_cmd_size_check: 11718 callbacks suppressed
... 
snip, continues a lot
....

# saveconfig.json

{
  "fabric_modules": [],
  "storage_objects": [
    {
      "aio": false,
      "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": {
        "alua_support": 1,
        "block_size": 4096,
        "emulate_3pc": 1,
        "emulate_caw": 1,
        "emulate_dpo": 1,
        "emulate_fua_read": 1,
        "emulate_fua_write": 1,
        "emulate_model_alias": 1,
        "emulate_pr": 1,
        "emulate_rest_reord": 0,
        "emulate_tas": 1,
        "emulate_tpu": 1,
        "emulate_tpws": 1,
        "emulate_ua_intlck_ctrl": 0,
        "emulate_write_cache": 1,
        "enforce_pr_isids": 1,
        "force_pr_aptpl": 0,
        "is_nonrot": 0,
        "max_unmap_block_desc_count": 1,
        "max_unmap_lba_count": 8192,
        "max_write_same_len": 4096,
        "optimal_sectors": 2048,
        "pgr_support": 1,
        "pi_prot_format": 0,
        "pi_prot_type": 0,
        "pi_prot_verify": 0,
        "queue_depth": 128,
        "unmap_granularity": 1,
        "unmap_granularity_alignment": 0,
        "unmap_zeroes_data": 0
      },
      "dev": "/media/iscsi-tgt/media_1.bin",
      "name": "media_1",
      "plugin": "fileio",
      "size": 858993459200,
      "write_back": true,
      "wwn": "d28ec22e-f29e-4c96-9019-0204730c538b"
    },
    {
      "aio": false,
      "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": {
        "alua_support": 1,
        "block_size": 4096,
        "emulate_3pc": 1,
        "emulate_caw": 1,
        "emulate_dpo": 1,
        "emulate_fua_read": 1,
        "emulate_fua_write": 1,
        "emulate_model_alias": 1,
        "emulate_pr": 1,
        "emulate_rest_reord": 0,
        "emulate_tas": 1,
        "emulate_tpu": 1,
        "emulate_tpws": 1,
        "emulate_ua_intlck_ctrl": 0,
        "emulate_write_cache": 1,
        "enforce_pr_isids": 1,
        "force_pr_aptpl": 0,
        "is_nonrot": 1,
        "max_unmap_block_desc_count": 1,
        "max_unmap_lba_count": 8192,
        "max_write_same_len": 4096,
        "optimal_sectors": 2048,
        "pgr_support": 1,
        "pi_prot_format": 0,
        "pi_prot_type": 0,
        "pi_prot_verify": 0,
        "queue_depth": 128,
        "unmap_granularity": 1,
        "unmap_granularity_alignment": 0,
        "unmap_zeroes_data": 0
      },
      "dev": "/media/iscsi-tgt/dep_1.bin",
      "name": "dep_1",
      "plugin": "fileio",
      "size": 966367641600,
      "write_back": true,
      "wwn": "a844aa27-dd49-4025-9ae0-20f85557ab32"
    }
  ],
  "targets": [
    {
      "fabric": "iscsi",
      "parameters": {
        "cmd_completion_affinity": "-1"
      },
      "tpgs": [
        {
          "attributes": {
            "authentication": 0,
            "cache_dynamic_acls": 0,
            "default_cmdsn_depth": 64,
            "default_erl": 2,
            "demo_mode_discovery": 1,
            "demo_mode_write_protect": 1,
            "fabric_prot_type": 0,
            "generate_node_acls": 0,
            "login_keys_workaround": 1,
            "login_timeout": 15,
            "netif_timeout": 2,
            "prod_mode_write_protect": 0,
            "t10_pi": 1,
            "tpg_enabled_sendtargets": 1
          },
          "enable": true,
          "luns": [
            {
              "alias": "8f17e89b4f",
              "alua_tg_pt_gp_name": "default_tg_pt_gp",
              "index": 0,
              "storage_object": "/backstores/fileio/dep_1"
            },
            {
              "alias": "a5a9f51905",
              "alua_tg_pt_gp_name": "default_tg_pt_gp",
              "index": 1,
              "storage_object": "/backstores/fileio/media_1"
            }
          ],
          "node_acls": [
            {
              "attributes": {
                "dataout_timeout": 5,
                "dataout_timeout_retries": 5,
                "default_erl": 2,
                "nopin_response_timeout": 30,
                "nopin_timeout": 15,
                "random_datain_pdu_offsets": 0,
                "random_datain_seq_offsets": 0,
                "random_r2t_offsets": 0
              },
              "mapped_luns": [
                {
                  "alias": "8c4e02bd30",
                  "index": 1,
                  "tpg_lun": 1,
                  "write_protect": false
                },
                {
                  "alias": "360e15af50",
                  "index": 0,
                  "tpg_lun": 0,
                  "write_protect": false
                }
              ],
              "node_wwn": "iqn.1991-05.com.microsoft:srv01"
            }
          ],
          "parameters": {
            "AuthMethod": "CHAP,None",
            "DataDigest": "CRC32C",
            "DataPDUInOrder": "Yes",
            "DataSequenceInOrder": "Yes",
            "DefaultTime2Retain": "20",
            "DefaultTime2Wait": "2",
            "ErrorRecoveryLevel": "0",
            "FirstBurstLength": "65536",
            "HeaderDigest": "CRC32C",
            "IFMarkInt": "Reject",
            "IFMarker": "No",
            "ImmediateData": "Yes",
            "InitialR2T": "Yes",
            "MaxBurstLength": "262144",
            "MaxConnections": "1",
            "MaxOutstandingR2T": "1",
            "MaxRecvDataSegmentLength": "8192",
            "MaxXmitDataSegmentLength": "262144",
            "OFMarkInt": "Reject",
            "OFMarker": "No",
            "TargetAlias": "LIO Target"
          },
          "portals": [
            {
              "ip_address": "0.0.0.0",
              "iser": false,
              "offload": false,
              "port": 3260
            }
          ],
          "tag": 1
        }
      ],
      "wwn": "iqn.2022-02.com.xxxxxx:srv01"
    }
  ]
}

Hello, this is a kernel issue. targetcli is just a userspace tool used to configure the target, the rest of the work is done by the kernel driver.
I think you should send this dmesg output to the target-devel mailing list (target-devel@vger.kernel.org)