[Bug 259152] [iscsi] ExpDataSN mismatch in SCSI Response (unable to connect or authenticate to OCI oracle iscsi block devices)

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=259152

            Bug ID: 259152
           Summary: [iscsi] ExpDataSN mismatch in SCSI Response (unable to
                    connect or authenticate to OCI oracle iscsi block
                    devices)
           Product: Base System
           Version: CURRENT
          Hardware: arm64
                OS: Any
            Status: New
          Severity: Affects Some People
          Priority: ---
         Component: kern
          Assignee: bugs@FreeBSD.org
          Reporter: dch@freebsd.org

Created attachment 228677
  --> https://bugs.freebsd.org/bugzilla/attachment.cgi?id=228677&action=edit
pcap on port 3260 during this transaction

## environment

- Freebsd 14.0-CURRENT 6882064d0ced456c89d161da4bc43c5d97bab60b (2021-10-12)
- OCI hosted iscsi block storage
- neither boot volumes (no auth required) nor additional volumes (with auth)
will connect correctly
- pcap + wireshark suggests that the login + response is correct from protocol
perspective
- fiddling with MTU (1500 -> 9000 -> 16000) seems not to help

## logs

these are taken from a VM as it's easier to get pcap (attached)

### equivalent linux commands (oracle linux ofc)
sudo iscsiadm -m node -o new -T
iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1 -p
169.254.2.3:3260
sudo iscsiadm -m node -o update -T
iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1 -n node.startup
-v automatic
sudo iscsiadm -m node -T
iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1 -p
169.254.2.3:3260 -l

### freebsd term
# cat /etc/iscsi.conf
behemoth {
        TargetAddress   = 169.254.2.3:3260
        TargetName      =
iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1
}

# sysctl kern.iscsi.debug=10
# tail -qF /var/log/messages | egrep --line-buffered 'cam|icsci' &
# ngrep -qid vtnet0 -O /tmp/iscsi.pcap . port 3260 &
# iscsictl -Aa

[3858] vtnet0: promiscuous mode enabled
[3883] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3883] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3883] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3883] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3883] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3883] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3883] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3883] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3883] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3883] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3883] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3884] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3884] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3884] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3884] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3884] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3884] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3884] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3884] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3884] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3884] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3884] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3884] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3885] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3885] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3885] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3885] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3885] iscsi_ioctl_daemon_handoff: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): releasing
[3885] WARNING: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): ExpDataSN
mismatch in SCSI Response (0 vs 1)
[3885] iscsi_session_cleanup: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
[3885] iscsi_session_terminate_task: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): freezing
devq
[3885] iscsi_ioctl_daemon_fail: 169.254.2.3:3260
(iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1): iscsid(8)
failed: Connection refused

# iscsictl -Lv
Session ID:               2
Initiator name:           iqn.1994-09.org.freebsd:a01.cabal5.net
Initiator portal:
Initiator alias:
Target name:             
iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1
Target portal:            169.254.2.3:3260
Target alias:
User:
Secret:
Mutual user:
Mutual secret:
Session type:             Normal
Enable:                   Yes
Session state:            Disconnected
Failure reason:           Connection refused
Header digest:            None
Data digest:              None
MaxRecvDataSegmentLength: 8192
MaxSendDataSegmentLength: 8192
MaxBurstLen:              262144
FirstBurstLen:            65536
ImmediateData:            Yes
iSER (RDMA):              No
Offload driver:           None
Device nodes:             probe0



## wireshark dump from pcap

### client -> server
iSCSI (Login Command)
    Opcode: Login Command (0x03)
    1... .... = T: Transit to next login stage
    .0.. .... = C: Text is complete
    .... 00.. = CSG: Security negotiation (0x0)
    .... ..01 = NSG: Operational negotiation (0x1)
    VersionMax: 0x00
    VersionMin: 0x00
    TotalAHSLength: 0x00
    DataSegmentLength: 163 (0x000000a3)
    ISID: 80 12 4a 8c 6f 4f
        10.. .... = ISID_t: Random (0x2)
        ..00 0000 = ISID_a: 0x00
        ISID_b: 0x124a
        ISID_c: 0x8c
        ISID_d: 0x6f4f
    TSIH: 0x0000
    InitiatorTaskTag: 0x00000000
    CID: 0x0000
    CmdSN: 0x00000000
    ExpStatSN: 0x00000001
    Key/Value Pairs
        KeyValue: AuthMethod=None
        KeyValue: InitiatorName=iqn.1994-09.org.freebsd:a01.cabal5.net
        KeyValue: SessionType=Normal
        KeyValue:
TargetName=iqn.2015-12.com.oracleiaas:96df523d-a0c4-4d20-9d97-6900e94a1bc1
    Padding: 00

### server -> client

iSCSI (Login Response)
    Opcode: Login Response (0x23)
    1... .... = T: Transit to next login stage
    .0.. .... = C: Text is complete
    .... 01.. = CSG: Operational negotiation (0x1)
    .... ..11 = NSG: Full feature phase (0x3)
    VersionMax: 0x00
    VersionActive: 0x00
    TotalAHSLength: 0x00
    DataSegmentLength: 226 (0x000000e2)
    ISID: 80 12 4a 8c 6f 4f
        10.. .... = ISID_t: Random (0x2)
        ..00 0000 = ISID_a: 0x00
        ISID_b: 0x124a
        ISID_c: 0x8c
        ISID_d: 0x6f4f
    TSIH: 0x0100
    InitiatorTaskTag: 0x00000000
    StatSN: 0x00000001
    ExpCmdSN: 0x00000000
    MaxCmdSN: 0x00000001
    Status: Success (0x0000)
    Key/Value Pairs
        KeyValue: iSCSIProtocolLevel=NotUnderstood
        KeyValue: HeaderDigest=None
        KeyValue: DataDigest=None
        KeyValue: ImmediateData=Yes
        KeyValue: MaxBurstLength=262144
        KeyValue: FirstBurstLength=65536
        KeyValue: InitialR2T=Yes
        KeyValue: MaxOutstandingR2T=1
        KeyValue: DefaultTime2Wait=2
        KeyValue: DefaultTime2Retain=0
        KeyValue: ErrorRecoveryLevel=0
    Padding: 00 00

### client -> server

iSCSI (SCSI Command)
    Opcode: SCSI Command (0x01)
    .0.. .... = I: Queued delivery
    TotalAHSLength: 0x00
    DataSegmentLength: 0 (0x00000000)
    LUN
        00.. .... = Address Mode: Simple logical unit addressing (0x00)
        ..00 0000  0000 0000 = LUN: 0x0000
    InitiatorTaskTag: 0x05000000
    ExpectedDataTransferLength: 0x00000018
    CmdSN: 0x00000000
    ExpStatSN: 0x00000002
    Data In in: 21
    Response in: 21
Flags: 0xc0, F, R, Attr: Untagged
    1... .... = F: Final PDU in sequence
    .1.. .... = R: Data will be read from target
    ..0. .... = W: No data will be written to target
    .... .000 = Attr: Untagged (0x0)
SCSI CDB Mode Sense(6)
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [Response in: 21]
    Opcode: Mode Sense(6) (0x1a)
    DBD = 0
    00.. .... = Page Control: Current Values (0)
    ..00 1010 = SPC-2 Page Code: Control (0x0a)
    Allocation Length: 24
    Control: 0x00
        00.. .... = Vendor specific: 0x0
        ..00 0... = Reserved: 0x0
        .... .0.. = NACA: Normal ACA is not set
        .... ..0. = Obsolete: 0x0
        .... ...0 = Obsolete: 0x0

### server -> client

iSCSI (SCSI Data In)
    Opcode: SCSI Data In (0x25)
    Flags: 0x80
        1... .... = F: Final PDU in sequence
        .0.. .... = A: Acknowledge not requested
        .... .0.. = O: No residual overflow occurred
        .... ..0. = U: No residual underflow occurred
        .... ...0 = S: Response does not contain SCSI status
    TotalAHSLength: 0x00
    DataSegmentLength: 24 (0x00000018)
    InitiatorTaskTag: 0x05000000
    StatSN: 0x00000000
    ExpCmdSN: 0x00000001
    MaxCmdSN: 0x00000081
    DataSN: 0x00000000
    BufferOffset: 0x00000000
    ResidualCount: 0x00000000
    Request in: 20
    Response in: 21
SCSI Payload (Mode Sense(6) Response Data)
    [LUN: 0x0000]
    [Command Set:Direct Access Device (0x00) (Using default commandset)]
    [SBC Opcode: Mode Sense(6) (0x1a)]
    [Request in: 20]
    [Response in: 21]
    Mode Data Length: 0
iSCSI (SCSI Response)
    Opcode: SCSI Response (0x21)
    Response: Command completed at target (0x00)
    Status: Check Condition (0x02)
    TotalAHSLength: 0x00
    DataSegmentLength: 20 (0x00000014)
    InitiatorTaskTag: 0x05000000
    StatSN: 0x00000002
    ExpCmdSN: 0x00000001
    MaxCmdSN: 0x00000081
    ExpDataSN: 0x00000000
    BidiReadResidualCount: 0x00000000
    ResidualCount: 0x00000000
    Request in: 20
    Time from request: 0.000114000 seconds
    Data In in: 21
    SenseLength: 0x0012
Flags: 0x80
    ...0 .... = o: No overflow of read part of bi-directional command
    .... 0... = u: No underflow of read part of bi-directional command
    .... .0.. = O: No residual overflow occurred
    .... ..0. = U: No residual underflow occurred
SCSI: SNS Info
    [LUN: 0x0000]
    .111 0000 = SNS Error Type: Current Error (0x70)
    Valid: 112
    0... .... = Filemark: False
    .0.. .... = EOM: False
    ..0. .... = ILI: False
    .... 0110 = Sense Key: Unit Attention (0x6)
    Sense Info: 0x00000000
    Additional Sense Length: 10
    Command-Specific Information: 00 00 00 00
    Additional Sense Code+Qualifier: Power On, Reset, Or Bus Device Reset
Occurred (0x2900)
    <Additional Sense Code: 0x29>
    <Additional Sense Code Qualifier: 0x00>
    Field Replaceable Unit Code: 0x00
    0... .... = SKSV: False
    .000 0000 0000 0000 0000 0000 = Sense Key Specific: 0x000000


AFAICT this repeats until connection is dropped

-- 
You are receiving this mail because:
You are the assignee for the bug.