Skip to content

Commit

Permalink
ocs_fc: IO timeout handling and error reporting fix.
Browse files Browse the repository at this point in the history 
Hardware timeout uses a 8-bit timeout value and expects the timeout to
be less than 255 seconds. Added software timer implemetation to timeout
and abort the IOs with timeout more than 255 seconds.

Fix the timeout problem by dividing CAM timeouts by 1000 as hardware
expects timeout value in seconds.  Before this change, CAM timeouts in
milliseconds were getting truncated to 8 bits and converted to seconds.
So the actual timeout used when going down to the card would depend on
the bottom 8 bits of the timeout used.

Add the mapping of ocs_fc error status to CAM status.

Reported by:	ken
Reviewed by:	ken
Tested by:	ken, ram
Approved by:	ken
MFC after:	1 week

(cherry picked from commit 7054754)
  • Loading branch information
Ram Kishore Vegesna authored and Ram Kishore Vegesna committed Dec 27, 2023
1 parent 42b80d1 commit 104eae5
Show file tree
Hide file tree
Showing 6 changed files with 144 additions and 39 deletions.
87 changes: 84 additions & 3 deletions sys/dev/ocs_fc/ocs_cam.c
View file
Expand Up @@ -44,6 +44,7 @@
#include "ocs.h"
#include "ocs_scsi.h"
#include "ocs_device.h"
#include <sys/sbuf.h>

/* Default IO timeout value for initiators is 30 seconds */
#define OCS_CAM_IO_TIMEOUT 30
Expand All @@ -55,6 +56,27 @@ typedef struct {
int32_t rc;
} ocs_dmamap_load_arg_t;

struct ocs_scsi_status_desc {
ocs_scsi_io_status_e status;
const char *desc;
} ocs_status_desc[] = {
{ OCS_SCSI_STATUS_GOOD, "Good" },
{ OCS_SCSI_STATUS_ABORTED, "Aborted" },
{ OCS_SCSI_STATUS_ERROR, "Error" },
{ OCS_SCSI_STATUS_DIF_GUARD_ERROR, "DIF Guard Error" },
{ OCS_SCSI_STATUS_DIF_REF_TAG_ERROR, "DIF REF Tag Error" },
{ OCS_SCSI_STATUS_DIF_APP_TAG_ERROR, "DIF App Tag Error" },
{ OCS_SCSI_STATUS_DIF_UNKNOWN_ERROR, "DIF Unknown Error" },
{ OCS_SCSI_STATUS_PROTOCOL_CRC_ERROR, "Proto CRC Error" },
{ OCS_SCSI_STATUS_NO_IO, "No IO" },
{ OCS_SCSI_STATUS_ABORT_IN_PROGRESS, "Abort in Progress" },
{ OCS_SCSI_STATUS_CHECK_RESPONSE, "Check Response" },
{ OCS_SCSI_STATUS_COMMAND_TIMEOUT, "Command Timeout" },
{ OCS_SCSI_STATUS_TIMEDOUT_AND_ABORTED, "Timed out and Aborted" },
{ OCS_SCSI_STATUS_SHUTDOWN, "Shutdown" },
{ OCS_SCSI_STATUS_NEXUS_LOST, "Nexus Lost" }
};

static void ocs_action(struct cam_sim *, union ccb *);
static void ocs_poll(struct cam_sim *);

Expand Down Expand Up @@ -1497,7 +1519,7 @@ static int32_t ocs_scsi_initiator_io_cb(ocs_io_t *io,
* If we've already got a SCSI error, prefer that because it
* will have more detail.
*/
if ((rsp->residual < 0) && (ccb_status == CAM_REQ_CMP)) {
if ((rsp->residual < 0) && (ccb_status == CAM_REQ_CMP)) {
ccb_status = CAM_DATA_RUN_ERR;
}

Expand All @@ -1517,7 +1539,62 @@ static int32_t ocs_scsi_initiator_io_cb(ocs_io_t *io,
ocs_memcpy(&csio->sense_data, rsp->sense_data, sense_len);
}
} else if (scsi_status != OCS_SCSI_STATUS_GOOD) {
ccb_status = CAM_REQ_CMP_ERR;
const char *err_desc = NULL;
char path_str[64];
char err_str[224];
struct sbuf sb;
size_t i;

sbuf_new(&sb, err_str, sizeof(err_str), 0);

xpt_path_string(ccb->ccb_h.path, path_str, sizeof(path_str));
sbuf_cat(&sb, path_str);

for (i = 0; i < (sizeof(ocs_status_desc) /
sizeof(ocs_status_desc[0])); i++) {
if (scsi_status == ocs_status_desc[i].status) {
err_desc = ocs_status_desc[i].desc;
break;
}
}
if (ccb->ccb_h.func_code == XPT_SCSI_IO) {
scsi_command_string(&ccb->csio, &sb);
sbuf_printf(&sb, "length %d ", ccb->csio.dxfer_len);
}
sbuf_printf(&sb, "error status %d (%s)\n", scsi_status,
(err_desc != NULL) ? err_desc : "Unknown");
sbuf_finish(&sb);
printf("%s", sbuf_data(&sb));

switch (scsi_status) {
case OCS_SCSI_STATUS_ABORTED:
case OCS_SCSI_STATUS_ABORT_IN_PROGRESS:
ccb_status = CAM_REQ_ABORTED;
break;
case OCS_SCSI_STATUS_DIF_GUARD_ERROR:
case OCS_SCSI_STATUS_DIF_REF_TAG_ERROR:
case OCS_SCSI_STATUS_DIF_APP_TAG_ERROR:
case OCS_SCSI_STATUS_DIF_UNKNOWN_ERROR:
case OCS_SCSI_STATUS_PROTOCOL_CRC_ERROR:
ccb_status = CAM_IDE;
break;
case OCS_SCSI_STATUS_ERROR:
case OCS_SCSI_STATUS_NO_IO:
ccb_status = CAM_REQ_CMP_ERR;
break;
case OCS_SCSI_STATUS_COMMAND_TIMEOUT:
case OCS_SCSI_STATUS_TIMEDOUT_AND_ABORTED:
ccb_status = CAM_CMD_TIMEOUT;
break;
case OCS_SCSI_STATUS_SHUTDOWN:
case OCS_SCSI_STATUS_NEXUS_LOST:
ccb_status = CAM_SCSI_IT_NEXUS_LOST;
break;
default:
ccb_status = CAM_REQ_CMP_ERR;
break;
}

} else {
ccb_status = CAM_REQ_CMP;
}
Expand Down Expand Up @@ -1842,7 +1919,11 @@ ocs_initiator_io(struct ocs_softc *ocs, union ccb *ccb)
} else if (ccb->ccb_h.timeout == CAM_TIME_DEFAULT) {
io->timeout = OCS_CAM_IO_TIMEOUT;
} else {
io->timeout = ccb->ccb_h.timeout;
if (ccb->ccb_h.timeout < 1000)
io->timeout = 1;
else {
io->timeout = ccb->ccb_h.timeout / 1000;
}
}

switch (csio->tag_action) {
Expand Down
70 changes: 44 additions & 26 deletions sys/dev/ocs_fc/ocs_hw.c
View file
Expand Up @@ -148,25 +148,37 @@ static void ocs_hw_check_sec_hio_list(ocs_hw_t *hw);
static void target_wqe_timer_cb(void *arg);
static void shutdown_target_wqe_timer(ocs_hw_t *hw);

/* WQE timeout for initiator IOs */
static inline uint8_t
ocs_hw_set_io_wqe_timeout(ocs_hw_io_t *io, uint32_t timeout)
{
if (timeout > 255) {
io->wqe_timeout = timeout;
return 0;
} else {
return timeout;
}
}

static inline void
ocs_hw_add_io_timed_wqe(ocs_hw_t *hw, ocs_hw_io_t *io)
{
if (hw->config.emulate_tgt_wqe_timeout && io->tgt_wqe_timeout) {
if (hw->config.emulate_wqe_timeout && io->wqe_timeout) {
/*
* Active WQE list currently only used for
* target WQE timeouts.
*/
ocs_lock(&hw->io_lock);
ocs_list_add_tail(&hw->io_timed_wqe, io);
io->submit_ticks = ocs_get_os_ticks();
getmicrouptime(&io->submit_time);
ocs_unlock(&hw->io_lock);
}
}

static inline void
ocs_hw_remove_io_timed_wqe(ocs_hw_t *hw, ocs_hw_io_t *io)
{
if (hw->config.emulate_tgt_wqe_timeout) {
if (hw->config.emulate_wqe_timeout) {
/*
* If target wqe timeouts are enabled,
* remove from active wqe list.
Expand Down Expand Up @@ -965,7 +977,7 @@ ocs_hw_init(ocs_hw_t *hw)
}

/* finally kick off periodic timer to check for timed out target WQEs */
if (hw->config.emulate_tgt_wqe_timeout) {
if (hw->config.emulate_wqe_timeout) {
ocs_setup_timer(hw->os, &hw->wqe_timer, target_wqe_timer_cb, hw,
OCS_HW_WQ_TIMER_PERIOD_MS);
}
Expand Down Expand Up @@ -1695,8 +1707,8 @@ ocs_hw_get(ocs_hw_t *hw, ocs_hw_property_e prop, uint32_t *value)
case OCS_HW_EMULATE_I_ONLY_AAB:
*value = hw->config.i_only_aab;
break;
case OCS_HW_EMULATE_TARGET_WQE_TIMEOUT:
*value = hw->config.emulate_tgt_wqe_timeout;
case OCS_HW_EMULATE_WQE_TIMEOUT:
*value = hw->config.emulate_wqe_timeout;
break;
case OCS_HW_VPD_LEN:
*value = sli_get_vpd_len(&hw->sli);
Expand Down Expand Up @@ -1996,8 +2008,8 @@ ocs_hw_set(ocs_hw_t *hw, ocs_hw_property_e prop, uint32_t value)
case OCS_HW_EMULATE_I_ONLY_AAB:
hw->config.i_only_aab = value;
break;
case OCS_HW_EMULATE_TARGET_WQE_TIMEOUT:
hw->config.emulate_tgt_wqe_timeout = value;
case OCS_HW_EMULATE_WQE_TIMEOUT:
hw->config.emulate_wqe_timeout = value;
break;
case OCS_HW_BOUNCE:
hw->config.bounce = value;
Expand Down Expand Up @@ -3324,7 +3336,7 @@ ocs_hw_init_free_io(ocs_hw_io_t *io)
io->type = 0xFFFF;
io->wq = NULL;
io->ul_io = NULL;
io->tgt_wqe_timeout = 0;
io->wqe_timeout = 0;
}

/**
Expand Down Expand Up @@ -3738,7 +3750,7 @@ ocs_hw_check_sec_hio_list(ocs_hw_t *hw)
flags &= ~SLI4_IO_CONTINUATION;
}

io->tgt_wqe_timeout = io->sec_iparam.fcp_tgt.timeout;
io->wqe_timeout = io->sec_iparam.fcp_tgt.timeout;

/* Complete (continue) TRECV IO */
if (io->xbusy) {
Expand Down Expand Up @@ -4041,6 +4053,7 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
ocs_hw_rtn_e rc = OCS_HW_RTN_SUCCESS;
uint32_t rpi;
uint8_t send_wqe = TRUE;
uint8_t timeout = 0;

CPUTRACE("");

Expand Down Expand Up @@ -4075,6 +4088,8 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
*/
switch (type) {
case OCS_HW_IO_INITIATOR_READ:
timeout = ocs_hw_set_io_wqe_timeout(io, iparam->fcp_ini.timeout);

/*
* If use_dif_quarantine workaround is in effect, and dif_separates then mark the
* initiator read IO for quarantine
Expand All @@ -4090,12 +4105,14 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
if (sli_fcp_iread64_wqe(&hw->sli, io->wqe.wqebuf, hw->sli.config.wqe_size, &io->def_sgl, io->first_data_sge, len,
io->indicator, io->reqtag, SLI4_CQ_DEFAULT, rpi, rnode,
iparam->fcp_ini.dif_oper, iparam->fcp_ini.blk_size,
iparam->fcp_ini.timeout)) {
timeout)) {
ocs_log_err(hw->os, "IREAD WQE error\n");
rc = OCS_HW_RTN_ERROR;
}
break;
case OCS_HW_IO_INITIATOR_WRITE:
timeout = ocs_hw_set_io_wqe_timeout(io, iparam->fcp_ini.timeout);

ocs_hw_io_ini_sge(hw, io, iparam->fcp_ini.cmnd, iparam->fcp_ini.cmnd_size,
iparam->fcp_ini.rsp);

Expand All @@ -4104,18 +4121,20 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
io->indicator, io->reqtag,
SLI4_CQ_DEFAULT, rpi, rnode,
iparam->fcp_ini.dif_oper, iparam->fcp_ini.blk_size,
iparam->fcp_ini.timeout)) {
timeout)) {
ocs_log_err(hw->os, "IWRITE WQE error\n");
rc = OCS_HW_RTN_ERROR;
}
break;
case OCS_HW_IO_INITIATOR_NODATA:
timeout = ocs_hw_set_io_wqe_timeout(io, iparam->fcp_ini.timeout);

ocs_hw_io_ini_sge(hw, io, iparam->fcp_ini.cmnd, iparam->fcp_ini.cmnd_size,
iparam->fcp_ini.rsp);

if (sli_fcp_icmnd64_wqe(&hw->sli, io->wqe.wqebuf, hw->sli.config.wqe_size, &io->def_sgl,
io->indicator, io->reqtag, SLI4_CQ_DEFAULT,
rpi, rnode, iparam->fcp_ini.timeout)) {
rpi, rnode, timeout)) {
ocs_log_err(hw->os, "ICMND WQE error\n");
rc = OCS_HW_RTN_ERROR;
}
Expand All @@ -4137,7 +4156,7 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
flags &= ~SLI4_IO_CONTINUATION;
}

io->tgt_wqe_timeout = iparam->fcp_tgt.timeout;
io->wqe_timeout = iparam->fcp_tgt.timeout;

/*
* If use_dif_quarantine workaround is in effect, and this is a DIF enabled IO
Expand Down Expand Up @@ -4227,7 +4246,7 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
flags &= ~SLI4_IO_CONTINUATION;
}

io->tgt_wqe_timeout = iparam->fcp_tgt.timeout;
io->wqe_timeout = iparam->fcp_tgt.timeout;
if (sli_fcp_tsend64_wqe(&hw->sli, io->wqe.wqebuf, hw->sli.config.wqe_size, &io->def_sgl, io->first_data_sge,
iparam->fcp_tgt.offset, len, io->indicator, io->reqtag,
SLI4_CQ_DEFAULT,
Expand Down Expand Up @@ -4260,7 +4279,7 @@ ocs_hw_io_send(ocs_hw_t *hw, ocs_hw_io_type_e type, ocs_hw_io_t *io,
}
}

io->tgt_wqe_timeout = iparam->fcp_tgt.timeout;
io->wqe_timeout = iparam->fcp_tgt.timeout;
if (sli_fcp_trsp64_wqe(&hw->sli, io->wqe.wqebuf, hw->sli.config.wqe_size,
&io->def_sgl,
len,
Expand Down Expand Up @@ -11173,9 +11192,8 @@ target_wqe_timer_nop_cb(ocs_hw_t *hw, int32_t status, uint8_t *mqe, void *arg)
{
ocs_hw_io_t *io = NULL;
ocs_hw_io_t *io_next = NULL;
uint64_t ticks_current = ocs_get_os_ticks();
uint32_t sec_elapsed;
ocs_hw_rtn_e rc;
struct timeval cur_time;

sli4_mbox_command_header_t *hdr = (sli4_mbox_command_header_t *)mqe;

Expand All @@ -11188,27 +11206,28 @@ target_wqe_timer_nop_cb(ocs_hw_t *hw, int32_t status, uint8_t *mqe, void *arg)
/* loop through active WQE list and check for timeouts */
ocs_lock(&hw->io_lock);
ocs_list_foreach_safe(&hw->io_timed_wqe, io, io_next) {
sec_elapsed = ((ticks_current - io->submit_ticks) / ocs_get_os_tick_freq());

/*
* If elapsed time > timeout, abort it. No need to check type since
* it wouldn't be on this list unless it was a target WQE
*/
if (sec_elapsed > io->tgt_wqe_timeout) {
ocs_log_test(hw->os, "IO timeout xri=0x%x tag=0x%x type=%d\n",
io->indicator, io->reqtag, io->type);
getmicrouptime(&cur_time);
timevalsub(&cur_time, &io->submit_time);
if (cur_time.tv_sec > io->wqe_timeout) {
ocs_log_info(hw->os, "IO timeout xri=0x%x tag=0x%x type=%d elasped time:%u\n",
io->indicator, io->reqtag, io->type, cur_time.tv_sec);

/* remove from active_wqe list so won't try to abort again */
ocs_list_remove(&hw->io_timed_wqe, io);

/* save status of "timed out" for when abort completes */
io->status_saved = 1;
io->saved_status = SLI4_FC_WCQE_STATUS_TARGET_WQE_TIMEOUT;
io->saved_status = SLI4_FC_WCQE_STATUS_WQE_TIMEOUT;
io->saved_ext = 0;
io->saved_len = 0;

/* now abort outstanding IO */
rc = ocs_hw_io_abort(hw, io, FALSE, NULL, NULL);
rc = ocs_hw_io_abort(hw, io, TRUE, NULL, NULL);
if (rc) {
ocs_log_test(hw->os,
"abort failed xri=%#x tag=%#x rc=%d\n",
Expand Down Expand Up @@ -11237,7 +11256,6 @@ target_wqe_timer_cb(void *arg)

/* delete existing timer; will kick off new timer after checking wqe timeouts */
hw->in_active_wqe_timer = TRUE;
ocs_del_timer(&hw->wqe_timer);

/* Forward timer callback to execute in the mailbox completion processing context */
if (ocs_hw_async_call(hw, target_wqe_timer_nop_cb, hw)) {
Expand All @@ -11250,7 +11268,7 @@ shutdown_target_wqe_timer(ocs_hw_t *hw)
{
uint32_t iters = 100;

if (hw->config.emulate_tgt_wqe_timeout) {
if (hw->config.emulate_wqe_timeout) {
/* request active wqe timer shutdown, then wait for it to complete */
hw->active_wqe_timer_shutdown = TRUE;

Expand Down
10 changes: 5 additions & 5 deletions sys/dev/ocs_fc/ocs_hw.h
View file
Expand Up @@ -211,7 +211,7 @@ typedef enum {
OCS_HW_WAR_VERSION,
OCS_HW_DISABLE_AR_TGT_DIF,
OCS_HW_EMULATE_I_ONLY_AAB, /**< emulate IAAB=0 for initiator-commands only */
OCS_HW_EMULATE_TARGET_WQE_TIMEOUT, /**< enable driver timeouts for target WQEs */
OCS_HW_EMULATE_WQE_TIMEOUT, /**< enable driver timeouts for WQEs */
OCS_HW_LINK_CONFIG_SPEED,
OCS_HW_CONFIG_TOPOLOGY,
OCS_HW_BOUNCE,
Expand Down Expand Up @@ -520,7 +520,7 @@ typedef union ocs_hw_io_param_u {
ocs_hw_dif_blk_size_e blk_size;
uint32_t cmnd_size;
uint16_t flags;
uint8_t timeout;
uint32_t timeout;
uint32_t first_burst;
} fcp_ini;
} ocs_hw_io_param_t;
Expand Down Expand Up @@ -576,8 +576,8 @@ struct ocs_hw_io_s {
void *abort_arg; /**< argument passed to "abort done" callback */
ocs_ref_t ref; /**< refcount object */
size_t length; /**< needed for bug O127585: length of IO */
uint8_t tgt_wqe_timeout; /**< timeout value for target WQEs */
uint64_t submit_ticks; /**< timestamp when current WQE was submitted */
uint32_t wqe_timeout; /**< timeout value for WQEs */
struct timeval submit_time; /**< timestamp when current WQE was submitted */

uint32_t status_saved:1, /**< if TRUE, latched status should be returned */
abort_in_progress:1, /**< if TRUE, abort is in progress */
Expand Down Expand Up @@ -915,7 +915,7 @@ struct ocs_hw_s {
uint16_t auto_xfer_rdy_app_tag_value;
uint8_t dif_mode; /**< DIF mode to use */
uint8_t i_only_aab; /** Enable initiator-only auto-abort */
uint8_t emulate_tgt_wqe_timeout; /** Enable driver target wqe timeouts */
uint8_t emulate_wqe_timeout; /** Enable driver wqe timeouts */
uint32_t bounce:1;
const char *queue_topology; /**< Queue topology string */
uint8_t auto_xfer_rdy_t10_enable; /** Enable t10 PI for auto xfer ready */
Expand Down

0 comments on commit 104eae5

Please sign in to comment.