From a90520da3c4f91b19ca59b1e8e8ea6d7f35b361c Mon Sep 17 00:00:00 2001 From: zhenwei pi Date: Fri, 3 Nov 2023 10:54:11 +0800 Subject: [PATCH 1/4] Distinguish command timeout Distinguish command timeout from outqueue or waitqueue. For example, A command sequence: ...NOP,READ,WRITE... NOP OUT command has no dependence on backend media, it is expected to response soon. Once NOP timeout in libiscsi: a, the command is already sent to target, the target side does *not* response. b, the command is still pending in libiscsi. Separate the two cases for trouble shooting. Signed-off-by: zhenwei pi --- lib/pdu.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/lib/pdu.c b/lib/pdu.c index 702febed..dc7685fa 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -737,7 +737,7 @@ iscsi_timeout_scan(struct iscsi_context *iscsi) cmdsn_gap++; } ISCSI_LIST_REMOVE(&iscsi->outqueue, pdu); - iscsi_set_error(iscsi, "command timed out"); + iscsi_set_error(iscsi, "command timed out from outqueue"); iscsi_dump_pdu_header(iscsi, pdu->outdata.data); if (pdu->callback) { pdu->callback(iscsi, SCSI_STATUS_TIMEOUT, @@ -757,7 +757,7 @@ iscsi_timeout_scan(struct iscsi_context *iscsi) continue; } ISCSI_LIST_REMOVE(&iscsi->waitpdu, pdu); - iscsi_set_error(iscsi, "command timed out"); + iscsi_set_error(iscsi, "command timed out from waitqueue"); iscsi_dump_pdu_header(iscsi, pdu->outdata.data); if (pdu->callback) { pdu->callback(iscsi, SCSI_STATUS_TIMEOUT, From 6e8497e53fa22a687b5d74033dc66c24d17f559c Mon Sep 17 00:00:00 2001 From: zhenwei pi Date: Fri, 3 Nov 2023 11:22:38 +0800 Subject: [PATCH 2/4] Declare value-string maps as static These value-string maps is read-only, it should be constructed once during loading binary. Signed-off-by: zhenwei pi --- lib/scsi-lowlevel.c | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/lib/scsi-lowlevel.c b/lib/scsi-lowlevel.c index 3349c9ca..675f0619 100644 --- a/lib/scsi-lowlevel.c +++ b/lib/scsi-lowlevel.c @@ -135,7 +135,7 @@ value_string_find(struct value_string *values, int value) const char * scsi_sense_key_str(int key) { - struct value_string keys[] = { + static struct value_string keys[] = { {SCSI_SENSE_NO_SENSE, "NO SENSE"}, {SCSI_SENSE_RECOVERED_ERROR, @@ -173,7 +173,7 @@ scsi_sense_key_str(int key) const char * scsi_sense_ascq_str(int ascq) { - struct value_string ascqs[] = { + static struct value_string ascqs[] = { {SCSI_SENSE_ASCQ_SANITIZE_IN_PROGRESS, "SANITIZE_IN_PROGRESS"}, {SCSI_SENSE_ASCQ_WRITE_AFTER_SANITIZE_REQUIRED, @@ -245,7 +245,7 @@ scsi_sense_ascq_str(int ascq) const char * scsi_pr_type_str(enum scsi_persistent_out_type pr_type) { - struct value_string pr_type_strings[] = { + static struct value_string pr_type_strings[] = { {SCSI_PERSISTENT_RESERVE_TYPE_WRITE_EXCLUSIVE, "Write Exclusive"}, {SCSI_PERSISTENT_RESERVE_TYPE_EXCLUSIVE_ACCESS, From 283e99b322272604653820f2a0a55e9e3793d6e4 Mon Sep 17 00:00:00 2001 From: zhenwei pi Date: Fri, 3 Nov 2023 12:17:38 +0800 Subject: [PATCH 3/4] Introduce helper function scsi_opcode_str Convert SCSI opcode into string for trouble shooting. Signed-off-by: zhenwei pi --- include/scsi-lowlevel.h | 2 + lib/scsi-lowlevel.c | 100 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 102 insertions(+) diff --git a/include/scsi-lowlevel.h b/include/scsi-lowlevel.h index 16fe68c9..fe65daf7 100644 --- a/include/scsi-lowlevel.h +++ b/include/scsi-lowlevel.h @@ -205,6 +205,8 @@ EXTERN const char *scsi_sense_ascq_str(int ascq); EXTERN const char *scsi_pr_type_str(enum scsi_persistent_out_type pr_type); +EXTERN const char *scsi_opcode_str(int opcode); + enum scsi_xfer_dir { SCSI_XFER_NONE = 0, SCSI_XFER_READ = 1, diff --git a/lib/scsi-lowlevel.c b/lib/scsi-lowlevel.c index 675f0619..1e2a7af8 100644 --- a/lib/scsi-lowlevel.c +++ b/lib/scsi-lowlevel.c @@ -264,6 +264,106 @@ scsi_pr_type_str(enum scsi_persistent_out_type pr_type) return value_string_find(pr_type_strings, pr_type); } +const char * +scsi_opcode_str(int opcode) +{ + static struct value_string opcode_strings[] = { + {SCSI_OPCODE_TESTUNITREADY, + "TESTUNITREADY"}, + {SCSI_OPCODE_READ6, + "READ6"}, + {SCSI_OPCODE_INQUIRY, + "INQUIRY"}, + {SCSI_OPCODE_MODESELECT6, + "MODESELECT6"}, + {SCSI_OPCODE_RESERVE6, + "RESERVE6"}, + {SCSI_OPCODE_RELEASE6, + "RELEASE6"}, + {SCSI_OPCODE_MODESENSE6, + "MODESENSE6"}, + {SCSI_OPCODE_STARTSTOPUNIT, + "STARTSTOPUNIT"}, + {SCSI_OPCODE_PREVENTALLOW, + "PREVENTALLOW"}, + {SCSI_OPCODE_READCAPACITY10, + "READCAPACITY10"}, + {SCSI_OPCODE_READ10, + "READ10"}, + {SCSI_OPCODE_WRITE10, + "WRITE10"}, + {SCSI_OPCODE_WRITE_VERIFY10, + "WRITE VERIFY10"}, + {SCSI_OPCODE_VERIFY10, + "VERIFY10"}, + {SCSI_OPCODE_PREFETCH10, + "PREFETCH10"}, + {SCSI_OPCODE_SYNCHRONIZECACHE10, + "SYNCHRONIZECACHE10"}, + {SCSI_OPCODE_READ_DEFECT_DATA10, + "READ DEFECT DATA10"}, + {SCSI_OPCODE_WRITE_SAME10, + "WRITE SAME10"}, + {SCSI_OPCODE_UNMAP, + "UNMAP"}, + {SCSI_OPCODE_READTOC, + "READTOC"}, + {SCSI_OPCODE_SANITIZE, + "SANITIZE"}, + {SCSI_OPCODE_MODESELECT10, + "MODESELECT10"}, + {SCSI_OPCODE_MODESENSE10, + "MODESENSE10"}, + {SCSI_OPCODE_PERSISTENT_RESERVE_IN, + "PERSISTENT RESERVE IN"}, + {SCSI_OPCODE_PERSISTENT_RESERVE_OUT, + "PERSISTENT RESERVE OUT"}, + {SCSI_OPCODE_EXTENDED_COPY, + "EXTENDED COPY"}, + {SCSI_OPCODE_RECEIVE_COPY_RESULTS, + "RECEIVE COPY RESULTS"}, + {SCSI_OPCODE_READ16, + "READ16"}, + {SCSI_OPCODE_COMPARE_AND_WRITE, + "COMPARE AND WRITE"}, + {SCSI_OPCODE_WRITE16, + "WRITE16"}, + {SCSI_OPCODE_ORWRITE, + "ORWRITE"}, + {SCSI_OPCODE_WRITE_VERIFY16, + "WRITE VERIFY16"}, + {SCSI_OPCODE_VERIFY16, + "VERIFY16"}, + {SCSI_OPCODE_PREFETCH16, + "PREFETCH16"}, + {SCSI_OPCODE_SYNCHRONIZECACHE16, + "SYNCHRONIZECACHE16"}, + {SCSI_OPCODE_WRITE_SAME16, + "WRITE SAME16"}, + {SCSI_OPCODE_WRITE_ATOMIC16, + "WRITE ATOMIC16"}, + {SCSI_OPCODE_SERVICE_ACTION_IN, + "SERVICE ACTION IN"}, + {SCSI_OPCODE_REPORTLUNS, + "REPORTLUNS"}, + {SCSI_OPCODE_MAINTENANCE_IN, + "MAINTENANCE IN"}, + {SCSI_OPCODE_READ12, + "READ12"}, + {SCSI_OPCODE_WRITE12, + "WRITE12"}, + {SCSI_OPCODE_WRITE_VERIFY12, + "WRITE VERIFY12"}, + {SCSI_OPCODE_VERIFY12, + "VERIFY12"}, + {SCSI_OPCODE_READ_DEFECT_DATA12, + "READ DEFECT DATA12"}, + {0, NULL} + }; + + return value_string_find(opcode_strings, opcode); +} + uint64_t scsi_get_uint64(const unsigned char *c) { From 4c3ac5464a1727542d30a8a813aa0adacb8ec02e Mon Sep 17 00:00:00 2001 From: zhenwei pi Date: Fri, 3 Nov 2023 12:18:30 +0800 Subject: [PATCH 4/4] Dump opcode string in iscsi_dump_pdu_header() Now we have more friendly opcode message once error occurs: libiscsi:1 command timed out from waitqueue [...] libiscsi:2 PDU header: 01 c1 ... e9 88[READ16] 00 00 00 ... ^(human readable opcode string) Signed-off-by: zhenwei pi --- lib/pdu.c | 14 ++++++++++---- 1 file changed, 10 insertions(+), 4 deletions(-) diff --git a/lib/pdu.c b/lib/pdu.c index dc7685fa..5b67bee6 100644 --- a/lib/pdu.c +++ b/lib/pdu.c @@ -79,12 +79,18 @@ iscsi_itt_post_increment(struct iscsi_context *iscsi) { } void iscsi_dump_pdu_header(struct iscsi_context *iscsi, unsigned char *data) { - char dump[ISCSI_RAW_HEADER_SIZE*3+1]={0}; + char dump1[33*3+1]={0}; + char dump2[(ISCSI_RAW_HEADER_SIZE-33)*3+1]={0}; + const char *opcode; int i; - for (i=0;i