On 01/10/2014 03:41 PM, Mike Christie wrote: > On 1/10/14 12:11 AM, vaughan wrote: >> I haven't figure out why it's rejected with "bookmark invalid"(9) >> reason, rather than "command not supported". IMO "bookmark invalid" is >> used when minor protocol conflict such as final flag not set with >> non-write command. However, I haven't find error of this kind in >> report_opcode, so I guess it's not supported on the target. >> > > Is it possible to get a wireshark/tcpdump trace? It does not have to > be during boot. We just need to see what commands are sent and the > response the target is returning. > > I forgot we know some microsoft iscsi target people. We can just email > them with the trace to confirm what is going on with the target. The > trace seems to be easier for them than them interpreting linux kernel > logs. I enabled debug_iscsi_tcp, here is a more detailed log in normal connection. Does "conn error (1020)" mean it's target peer who disconnect the connection at the same time of reject report_opcode? If it is, I think iSCSI boot failure can't be avoided without disable write_same check on OEL. Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv in 52 bytes Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv read 0 bytes status 1 Dec 17 00:20:17 ol6u4gx64 kernel: sd 7:0:0:0: [sdc] Write Protect is off Dec 17 00:20:17 ol6u4gx64 kernel: sd 7:0:0:0: [sdc] Mode Sense: 03 00 00 00 Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_send_hdr_prep digest disabled Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_send_hdr_done Header done. Next segment size 0 total_size 0 Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_xmit xmit 48 bytes Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv in 52 bytes Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv read 0 bytes status 1 Dec 17 00:20:17 ol6u4gx64 kernel: sd 7:0:0:0: [sdc] Got wrong page Dec 17 00:20:17 ol6u4gx64 kernel: sd 7:0:0:0: [sdc] Assuming drive cache: write through Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_send_hdr_prep digest disabled Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_send_hdr_done Header done. Next segment size 0 total_size 0 Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_xmit xmit 48 bytes Dec 17 00:20:17 ol6u4gx64 iscsid: Connection4:0 to [target: iqn.1991-05.com.microsoft:test1, portal: 10.182.92.118,3260] through [iface: default] is operational now Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv in 96 bytes Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: pdu (op 0x1 itt 0xa) rejected. Reason code 0x9 Dec 17 00:20:17 ol6u4gx64 kernel: rejected iscsi cmd hdr:op 0x1, flags 0xc1, itt 0xa, data_length 512 CDB: a3 c 1 12 0 0 0 0 2 0 0 0 0 0 0 0 Dec 17 00:20:17 ol6u4gx64 kernel: iscsi_handle_reject: return 0 Dec 17 00:20:17 ol6u4gx64 kernel: __iscsi_complete_pdu:1165: iscsi_handle_reject return 0 Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_tcp_recv read 0 bytes status 1 Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: iscsi_sw_sk_state_check TCP_CLOSE|TCP_CLOSE_WAIT Dec 17 00:20:17 ol6u4gx64 kernel: connection4:0: detected conn error (1020) Dec 17 00:20:18 ol6u4gx64 iscsid: Kernel reported iSCSI connection 4:0 error (1020 - ISCSI_ERR_TCP_CONN_CLOSE: TCP connection closed) state (3) "rejected iscsi cmd hdr" line is added for debug as below. diff --git a/drivers/scsi/libiscsi.c b/drivers/scsi/libiscsi.c index d4b4b36..831786a 100644 --- a/drivers/scsi/libiscsi.c +++ b/drivers/scsi/libiscsi.c @@ -993,7 +993,9 @@ static int iscsi_handle_reject(struct iscsi_conn *conn, struct iscsi_hdr *hdr, { struct iscsi_reject *reject = (struct iscsi_reject *)hdr; struct iscsi_hdr rejected_pdu; + struct iscsi_scsi_req rejected_scsi_req; int opcode, rc = 0; + int i; conn->exp_statsn = be32_to_cpu(reject->statsn) + 1; @@ -1061,6 +1063,22 @@ static int iscsi_handle_reject(struct iscsi_conn *conn, struct iscsi_hdr *hdr, "pdu (op 0x%x itt 0x%x) rejected. Reason " "code 0x%x\n", rejected_pdu.opcode, rejected_pdu.itt, reject->reason); + if (reject->reason == ISCSI_REASON_BOOKMARK_INVALID && + rejected_pdu.opcode == ISCSI_OP_SCSI_CMD) { + memcpy(&rejected_scsi_req, data, sizeof(struct iscsi_hdr)); + printk("rejected iscsi cmd hdr:" + "op 0x%x, flags 0x%x, itt 0x%x, data_length %u ", + rejected_scsi_req.opcode, + rejected_scsi_req.flags, + rejected_scsi_req.itt, + be32_to_cpu(rejected_scsi_req.data_length)); + printk("CDB:"); + for (i = 0; i < ISCSI_CDB_SIZE; i++) { + printk(" %x", rejected_scsi_req.cdb[i]); + } + printk("\n"); + printk("%s: return %d\n", __FUNCTION__, rc); + } break; } return rc; -- To unsubscribe from this list: send the line "unsubscribe linux-scsi" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html