From 03298552cba38f7c805ed338826dc76c405465c7 Mon Sep 17 00:00:00 2001 From: Hiral Patel Date: Tue, 12 Feb 2013 17:00:58 -0800 Subject: [SCSI] fnic: fixing issues in device and firmware reset code 1. Handling overlapped firmware resets This fix serialize multiple firmware resets to avoid situation where fnic device fails to come up for link up event, when firmware resets are issued back to back. If there are overlapped firmware resets are issued, the firmware reset operation checks whether there is any firmware reset in progress, if so it polls for its completion in a loop with 100ms delay. 2. Handling device reset timeout fnic_device_reset code has been modified to handle Device reset timeout: - Issue terminate on device reset timeout. - Introduced flags field (one of the scratch fields in scsi_cmnd). With this, device reset request would have DEVICE_RESET flag set for other routines to determine the type of the request. Also modified fnic_terminate_rport_io, fnic_rport_exch_rset, completion routines to handle SCSI commands with DEVICE_RESET flag. 3. LUN/Device Reset hangs when issued through IOCTL using utilities like sg_reset. Each SCSI command is associated with a valid tag, fnic uses this tag to retrieve associated scsi command on completion. the LUN/Device Reset issued through IOCTL resulting into a SCSI command that is not associated with a valid tag. So fnic fails to retrieve associated scsi command on completion, which causes hang. This fix allocates tag, associates it with the scsi command and frees the tag, when the operation completed. 4. Preventing IOs during firmware reset. Current fnic implementation allows IO submissions during firmware reset. This fix synchronizes IO submissions and firmware reset operations. It ensures that IOs issued to fnic prior to reset will be issued to the firmware before firmware reset. Signed-off-by: Narsimhulu Musini Signed-off-by: Hiral Patel Signed-off-by: James Bottomley --- drivers/scsi/fnic/fnic_scsi.c | 384 ++++++++++++++++++++++++++++++++++++++---- 1 file changed, 352 insertions(+), 32 deletions(-) (limited to 'drivers/scsi/fnic/fnic_scsi.c') diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c index c40ce52ed7c..2f46509f5b5 100644 --- a/drivers/scsi/fnic/fnic_scsi.c +++ b/drivers/scsi/fnic/fnic_scsi.c @@ -165,6 +165,33 @@ static int free_wq_copy_descs(struct fnic *fnic, struct vnic_wq_copy *wq) } +/** + * __fnic_set_state_flags + * Sets/Clears bits in fnic's state_flags + **/ +void +__fnic_set_state_flags(struct fnic *fnic, unsigned long st_flags, + unsigned long clearbits) +{ + struct Scsi_Host *host = fnic->lport->host; + int sh_locked = spin_is_locked(host->host_lock); + unsigned long flags = 0; + + if (!sh_locked) + spin_lock_irqsave(host->host_lock, flags); + + if (clearbits) + fnic->state_flags &= ~st_flags; + else + fnic->state_flags |= st_flags; + + if (!sh_locked) + spin_unlock_irqrestore(host->host_lock, flags); + + return; +} + + /* * fnic_fw_reset_handler * Routine to send reset msg to fw @@ -175,9 +202,16 @@ int fnic_fw_reset_handler(struct fnic *fnic) int ret = 0; unsigned long flags; + /* indicate fwreset to io path */ + fnic_set_state_flags(fnic, FNIC_FLAGS_FWRESET); + skb_queue_purge(&fnic->frame_queue); skb_queue_purge(&fnic->tx_queue); + /* wait for io cmpl */ + while (atomic_read(&fnic->in_flight)) + schedule_timeout(msecs_to_jiffies(1)); + spin_lock_irqsave(&fnic->wq_copy_lock[0], flags); if (vnic_wq_copy_desc_avail(wq) <= fnic->wq_copy_desc_low[0]) @@ -193,9 +227,12 @@ int fnic_fw_reset_handler(struct fnic *fnic) if (!ret) FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Issued fw reset\n"); - else + else { + fnic_clear_state_flags(fnic, FNIC_FLAGS_FWRESET); FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Failed to issue fw reset\n"); + } + return ret; } @@ -351,16 +388,19 @@ static inline int fnic_queue_wq_copy_desc(struct fnic *fnic, */ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_cmnd *)) { - struct fc_lport *lp; + struct fc_lport *lp = shost_priv(sc->device->host); struct fc_rport *rport; struct fnic_io_req *io_req; - struct fnic *fnic; + struct fnic *fnic = lport_priv(lp); struct vnic_wq_copy *wq; int ret; int sg_count; unsigned long flags; unsigned long ptr; + if (unlikely(fnic_chk_state_flags_locked(fnic, FNIC_FLAGS_IO_BLOCKED))) + return SCSI_MLQUEUE_HOST_BUSY; + rport = starget_to_rport(scsi_target(sc->device)); ret = fc_remote_port_chkready(rport); if (ret) { @@ -369,20 +409,20 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ return 0; } - lp = shost_priv(sc->device->host); if (lp->state != LPORT_ST_READY || !(lp->link_up)) return SCSI_MLQUEUE_HOST_BUSY; + atomic_inc(&fnic->in_flight); + /* * Release host lock, use driver resource specific locks from here. * Don't re-enable interrupts in case they were disabled prior to the * caller disabling them. */ spin_unlock(lp->host->host_lock); + CMD_FLAGS(sc) = FNIC_CDB_REQ; /* Get a new io_req for this SCSI IO */ - fnic = lport_priv(lp); - io_req = mempool_alloc(fnic->io_req_pool, GFP_ATOMIC); if (!io_req) { ret = SCSI_MLQUEUE_HOST_BUSY; @@ -452,6 +492,7 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ } } out: + atomic_dec(&fnic->in_flight); /* acquire host lock before returning to SCSI */ spin_lock(lp->host->host_lock); return ret; @@ -529,6 +570,8 @@ static int fnic_fcpio_fw_reset_cmpl_handler(struct fnic *fnic, fnic_flush_tx(fnic); reset_cmpl_handler_end: + fnic_clear_state_flags(fnic, FNIC_FLAGS_FWRESET); + return ret; } @@ -656,8 +699,12 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, fcpio_header_dec(&desc->hdr, &type, &hdr_status, &tag); fcpio_tag_id_dec(&tag, &id); - if (id >= FNIC_MAX_IO_REQ) + if (id >= FNIC_MAX_IO_REQ) { + shost_printk(KERN_ERR, fnic->lport->host, + "Tag out of range tag %x hdr status = %s\n", + id, fnic_fcpio_status_to_str(hdr_status)); return; + } sc = scsi_host_find_tag(fnic->lport->host, id); WARN_ON_ONCE(!sc); @@ -805,8 +852,12 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, fcpio_header_dec(&desc->hdr, &type, &hdr_status, &tag); fcpio_tag_id_dec(&tag, &id); - if ((id & FNIC_TAG_MASK) >= FNIC_MAX_IO_REQ) + if ((id & FNIC_TAG_MASK) >= FNIC_MAX_IO_REQ) { + shost_printk(KERN_ERR, fnic->lport->host, + "Tag out of range tag %x hdr status = %s\n", + id, fnic_fcpio_status_to_str(hdr_status)); return; + } sc = scsi_host_find_tag(fnic->lport->host, id & FNIC_TAG_MASK); WARN_ON_ONCE(!sc); @@ -822,7 +873,19 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, return; } - if (id & FNIC_TAG_ABORT) { + if ((id & FNIC_TAG_ABORT) && (id & FNIC_TAG_DEV_RST)) { + /* Abort and terminate completion of device reset req */ + /* REVISIT : Add asserts about various flags */ + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "dev reset abts cmpl recd. id %x status %s\n", + id, fnic_fcpio_status_to_str(hdr_status)); + CMD_STATE(sc) = FNIC_IOREQ_ABTS_COMPLETE; + CMD_ABTS_STATUS(sc) = hdr_status; + CMD_FLAGS(sc) |= FNIC_DEV_RST_DONE; + if (io_req->abts_done) + complete(io_req->abts_done); + spin_unlock_irqrestore(io_lock, flags); + } else if (id & FNIC_TAG_ABORT) { /* Completion of abort cmd */ if (CMD_STATE(sc) != FNIC_IOREQ_ABTS_PENDING) { /* This is a late completion. Ignore it */ @@ -862,7 +925,27 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, } else if (id & FNIC_TAG_DEV_RST) { /* Completion of device reset */ CMD_LR_STATUS(sc) = hdr_status; + if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { + spin_unlock_irqrestore(io_lock, flags); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "Terminate pending " + "dev reset cmpl recd. id %d status %s\n", + (int)(id & FNIC_TAG_MASK), + fnic_fcpio_status_to_str(hdr_status)); + return; + } + if (CMD_FLAGS(sc) & FNIC_DEV_RST_TIMED_OUT) { + /* Need to wait for terminate completion */ + spin_unlock_irqrestore(io_lock, flags); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "dev reset cmpl recd after time out. " + "id %d status %s\n", + (int)(id & FNIC_TAG_MASK), + fnic_fcpio_status_to_str(hdr_status)); + return; + } CMD_STATE(sc) = FNIC_IOREQ_CMD_COMPLETE; + CMD_FLAGS(sc) |= FNIC_DEV_RST_DONE; FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "dev reset cmpl recd. id %d status %s\n", (int)(id & FNIC_TAG_MASK), @@ -889,7 +972,6 @@ static int fnic_fcpio_cmpl_handler(struct vnic_dev *vdev, struct fcpio_fw_req *desc) { struct fnic *fnic = vnic_dev_priv(vdev); - int ret = 0; switch (desc->hdr.type) { case FCPIO_ACK: /* fw copied copy wq desc to its queue */ @@ -906,11 +988,11 @@ static int fnic_fcpio_cmpl_handler(struct vnic_dev *vdev, case FCPIO_FLOGI_REG_CMPL: /* fw completed flogi_reg */ case FCPIO_FLOGI_FIP_REG_CMPL: /* fw completed flogi_fip_reg */ - ret = fnic_fcpio_flogi_reg_cmpl_handler(fnic, desc); + fnic_fcpio_flogi_reg_cmpl_handler(fnic, desc); break; case FCPIO_RESET_CMPL: /* fw completed reset */ - ret = fnic_fcpio_fw_reset_cmpl_handler(fnic, desc); + fnic_fcpio_fw_reset_cmpl_handler(fnic, desc); break; default: @@ -920,7 +1002,7 @@ static int fnic_fcpio_cmpl_handler(struct vnic_dev *vdev, break; } - return ret; + return 0; } /* @@ -962,6 +1044,23 @@ static void fnic_cleanup_io(struct fnic *fnic, int exclude_id) io_lock = fnic_io_lock_hash(fnic, sc); spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); + if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && + !(CMD_FLAGS(sc) & FNIC_DEV_RST_DONE)) { + /* + * We will be here only when FW completes reset + * without sending completions for outstanding ios. + */ + CMD_FLAGS(sc) |= FNIC_DEV_RST_DONE; + if (io_req && io_req->dr_done) + complete(io_req->dr_done); + else if (io_req && io_req->abts_done) + complete(io_req->abts_done); + spin_unlock_irqrestore(io_lock, flags); + continue; + } else if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) { + spin_unlock_irqrestore(io_lock, flags); + continue; + } if (!io_req) { spin_unlock_irqrestore(io_lock, flags); goto cleanup_scsi_cmd; @@ -1044,8 +1143,18 @@ static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag, struct fnic_io_req *io_req) { struct vnic_wq_copy *wq = &fnic->wq_copy[0]; + struct Scsi_Host *host = fnic->lport->host; unsigned long flags; + spin_lock_irqsave(host->host_lock, flags); + if (unlikely(fnic_chk_state_flags_locked(fnic, + FNIC_FLAGS_IO_BLOCKED))) { + spin_unlock_irqrestore(host->host_lock, flags); + return 1; + } else + atomic_inc(&fnic->in_flight); + spin_unlock_irqrestore(host->host_lock, flags); + spin_lock_irqsave(&fnic->wq_copy_lock[0], flags); if (vnic_wq_copy_desc_avail(wq) <= fnic->wq_copy_desc_low[0]) @@ -1053,6 +1162,9 @@ static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag, if (!vnic_wq_copy_desc_avail(wq)) { spin_unlock_irqrestore(&fnic->wq_copy_lock[0], flags); + atomic_dec(&fnic->in_flight); + shost_printk(KERN_DEBUG, fnic->lport->host, + "fnic_queue_abort_io_req: failure: no descriptors\n"); return 1; } fnic_queue_wq_copy_desc_itmf(wq, tag | FNIC_TAG_ABORT, @@ -1060,12 +1172,15 @@ static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag, fnic->config.ra_tov, fnic->config.ed_tov); spin_unlock_irqrestore(&fnic->wq_copy_lock[0], flags); + atomic_dec(&fnic->in_flight); + return 0; } -void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) +static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) { int tag; + int abt_tag; struct fnic_io_req *io_req; spinlock_t *io_lock; unsigned long flags; @@ -1075,13 +1190,14 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, - "fnic_rport_reset_exch called portid 0x%06x\n", + "fnic_rport_exch_reset called portid 0x%06x\n", port_id); if (fnic->in_remove) return; for (tag = 0; tag < FNIC_MAX_IO_REQ; tag++) { + abt_tag = tag; sc = scsi_host_find_tag(fnic->lport->host, tag); if (!sc) continue; @@ -1096,6 +1212,15 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) continue; } + if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "fnic_rport_exch_reset dev rst not pending sc 0x%p\n", + sc); + spin_unlock_irqrestore(io_lock, flags); + continue; + } + /* * Found IO that is still pending with firmware and * belongs to rport that went away @@ -1104,9 +1229,22 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) spin_unlock_irqrestore(io_lock, flags); continue; } + if (io_req->abts_done) { + shost_printk(KERN_ERR, fnic->lport->host, + "fnic_rport_exch_reset: io_req->abts_done is set " + "state is %s\n", + fnic_ioreq_state_to_str(CMD_STATE(sc))); + } + old_ioreq_state = CMD_STATE(sc); CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; CMD_ABTS_STATUS(sc) = FCPIO_INVALID_CODE; + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) { + abt_tag = (tag | FNIC_TAG_DEV_RST); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "fnic_rport_exch_reset dev rst sc 0x%p\n", + sc); + } BUG_ON(io_req->abts_done); @@ -1118,7 +1256,7 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) /* Now queue the abort command to firmware */ int_to_scsilun(sc->device->lun, &fc_lun); - if (fnic_queue_abort_io_req(fnic, tag, + if (fnic_queue_abort_io_req(fnic, abt_tag, FCPIO_ITMF_ABT_TASK_TERM, fc_lun.scsi_lun, io_req)) { /* @@ -1127,12 +1265,14 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) * aborted later by scsi_eh, or cleaned up during * lun reset */ - io_lock = fnic_io_lock_hash(fnic, sc); - spin_lock_irqsave(io_lock, flags); if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) CMD_STATE(sc) = old_ioreq_state; spin_unlock_irqrestore(io_lock, flags); + } else { + spin_lock_irqsave(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + spin_unlock_irqrestore(io_lock, flags); } } @@ -1141,6 +1281,7 @@ void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) void fnic_terminate_rport_io(struct fc_rport *rport) { int tag; + int abt_tag; struct fnic_io_req *io_req; spinlock_t *io_lock; unsigned long flags; @@ -1154,14 +1295,15 @@ void fnic_terminate_rport_io(struct fc_rport *rport) FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "fnic_terminate_rport_io called" - " wwpn 0x%llx, wwnn0x%llx, portid 0x%06x\n", - rport->port_name, rport->node_name, + " wwpn 0x%llx, wwnn0x%llx, rport 0x%p, portid 0x%06x\n", + rport->port_name, rport->node_name, rport, rport->port_id); if (fnic->in_remove) return; for (tag = 0; tag < FNIC_MAX_IO_REQ; tag++) { + abt_tag = tag; sc = scsi_host_find_tag(fnic->lport->host, tag); if (!sc) continue; @@ -1180,6 +1322,14 @@ void fnic_terminate_rport_io(struct fc_rport *rport) continue; } + if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "fnic_terminate_rport_io dev rst not pending sc 0x%p\n", + sc); + spin_unlock_irqrestore(io_lock, flags); + continue; + } /* * Found IO that is still pending with firmware and * belongs to rport that went away @@ -1188,9 +1338,20 @@ void fnic_terminate_rport_io(struct fc_rport *rport) spin_unlock_irqrestore(io_lock, flags); continue; } + if (io_req->abts_done) { + shost_printk(KERN_ERR, fnic->lport->host, + "fnic_terminate_rport_io: io_req->abts_done is set " + "state is %s\n", + fnic_ioreq_state_to_str(CMD_STATE(sc))); + } old_ioreq_state = CMD_STATE(sc); CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; CMD_ABTS_STATUS(sc) = FCPIO_INVALID_CODE; + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) { + abt_tag = (tag | FNIC_TAG_DEV_RST); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "fnic_terminate_rport_io dev rst sc 0x%p\n", sc); + } BUG_ON(io_req->abts_done); @@ -1203,7 +1364,7 @@ void fnic_terminate_rport_io(struct fc_rport *rport) /* Now queue the abort command to firmware */ int_to_scsilun(sc->device->lun, &fc_lun); - if (fnic_queue_abort_io_req(fnic, tag, + if (fnic_queue_abort_io_req(fnic, abt_tag, FCPIO_ITMF_ABT_TASK_TERM, fc_lun.scsi_lun, io_req)) { /* @@ -1212,12 +1373,14 @@ void fnic_terminate_rport_io(struct fc_rport *rport) * aborted later by scsi_eh, or cleaned up during * lun reset */ - io_lock = fnic_io_lock_hash(fnic, sc); - spin_lock_irqsave(io_lock, flags); if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) CMD_STATE(sc) = old_ioreq_state; spin_unlock_irqrestore(io_lock, flags); + } else { + spin_lock_irqsave(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + spin_unlock_irqrestore(io_lock, flags); } } @@ -1239,6 +1402,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) int ret = SUCCESS; u32 task_req; struct scsi_lun fc_lun; + int tag; DECLARE_COMPLETION_ONSTACK(tm_done); /* Wait for rport to unblock */ @@ -1249,9 +1413,14 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) fnic = lport_priv(lp); rport = starget_to_rport(scsi_target(sc->device)); - FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, - "Abort Cmd called FCID 0x%x, LUN 0x%x TAG %d\n", - rport->port_id, sc->device->lun, sc->request->tag); + tag = sc->request->tag; + FNIC_SCSI_DBG(KERN_DEBUG, + fnic->lport->host, + "Abort Cmd called FCID 0x%x, LUN 0x%x TAG %x flags %x\n", + rport->port_id, sc->device->lun, tag, CMD_FLAGS(sc)); + + CMD_FLAGS(sc) = FNIC_NO_FLAGS; + if (lp->state != LPORT_ST_READY || !(lp->link_up)) { ret = FAILED; @@ -1375,10 +1544,20 @@ static inline int fnic_queue_dr_io_req(struct fnic *fnic, struct fnic_io_req *io_req) { struct vnic_wq_copy *wq = &fnic->wq_copy[0]; + struct Scsi_Host *host = fnic->lport->host; struct scsi_lun fc_lun; int ret = 0; unsigned long intr_flags; + spin_lock_irqsave(host->host_lock, intr_flags); + if (unlikely(fnic_chk_state_flags_locked(fnic, + FNIC_FLAGS_IO_BLOCKED))) { + spin_unlock_irqrestore(host->host_lock, intr_flags); + return FAILED; + } else + atomic_inc(&fnic->in_flight); + spin_unlock_irqrestore(host->host_lock, intr_flags); + spin_lock_irqsave(&fnic->wq_copy_lock[0], intr_flags); if (vnic_wq_copy_desc_avail(wq) <= fnic->wq_copy_desc_low[0]) @@ -1399,6 +1578,7 @@ static inline int fnic_queue_dr_io_req(struct fnic *fnic, lr_io_req_end: spin_unlock_irqrestore(&fnic->wq_copy_lock[0], intr_flags); + atomic_dec(&fnic->in_flight); return ret; } @@ -1502,6 +1682,65 @@ clean_pending_aborts_end: return ret; } +/** + * fnic_scsi_host_start_tag + * Allocates tagid from host's tag list + **/ +static inline int +fnic_scsi_host_start_tag(struct fnic *fnic, struct scsi_cmnd *sc) +{ + struct blk_queue_tag *bqt = fnic->lport->host->bqt; + int tag, ret = SCSI_NO_TAG; + + BUG_ON(!bqt); + if (!bqt) { + pr_err("Tags are not supported\n"); + goto end; + } + + do { + tag = find_next_zero_bit(bqt->tag_map, bqt->max_depth, 1); + if (tag >= bqt->max_depth) { + pr_err("Tag allocation failure\n"); + goto end; + } + } while (test_and_set_bit(tag, bqt->tag_map)); + + bqt->tag_index[tag] = sc->request; + sc->request->tag = tag; + sc->tag = tag; + if (!sc->request->special) + sc->request->special = sc; + + ret = tag; + +end: + return ret; +} + +/** + * fnic_scsi_host_end_tag + * frees tag allocated by fnic_scsi_host_start_tag. + **/ +static inline void +fnic_scsi_host_end_tag(struct fnic *fnic, struct scsi_cmnd *sc) +{ + struct blk_queue_tag *bqt = fnic->lport->host->bqt; + int tag = sc->request->tag; + + if (tag == SCSI_NO_TAG) + return; + + BUG_ON(!bqt || !bqt->tag_index[tag]); + if (!bqt) + return; + + bqt->tag_index[tag] = NULL; + clear_bit(tag, bqt->tag_map); + + return; +} + /* * SCSI Eh thread issues a Lun Reset when one or more commands on a LUN * fail to get aborted. It calls driver's eh_device_reset with a SCSI command @@ -1517,7 +1756,10 @@ int fnic_device_reset(struct scsi_cmnd *sc) int ret = FAILED; spinlock_t *io_lock; unsigned long flags; + struct scsi_lun fc_lun; + int tag; DECLARE_COMPLETION_ONSTACK(tm_done); + int tag_gen_flag = 0; /*to track tags allocated by fnic driver*/ /* Wait for rport to unblock */ fc_block_scsi_eh(sc); @@ -1529,8 +1771,8 @@ int fnic_device_reset(struct scsi_cmnd *sc) rport = starget_to_rport(scsi_target(sc->device)); FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, - "Device reset called FCID 0x%x, LUN 0x%x\n", - rport->port_id, sc->device->lun); + "Device reset called FCID 0x%x, LUN 0x%x sc 0x%p\n", + rport->port_id, sc->device->lun, sc); if (lp->state != LPORT_ST_READY || !(lp->link_up)) goto fnic_device_reset_end; @@ -1539,6 +1781,16 @@ int fnic_device_reset(struct scsi_cmnd *sc) if (fc_remote_port_chkready(rport)) goto fnic_device_reset_end; + CMD_FLAGS(sc) = (FNIC_DEVICE_RESET | FNIC_BLOCKING_REQ); + /* Allocate tag if not present */ + + tag = sc->request->tag; + if (unlikely(tag < 0)) { + tag = fnic_scsi_host_start_tag(fnic, sc); + if (unlikely(tag == SCSI_NO_TAG)) + goto fnic_device_reset_end; + tag_gen_flag = 1; + } io_lock = fnic_io_lock_hash(fnic, sc); spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); @@ -1562,8 +1814,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) CMD_LR_STATUS(sc) = FCPIO_INVALID_CODE; spin_unlock_irqrestore(io_lock, flags); - FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "TAG %d\n", - sc->request->tag); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "TAG %x\n", tag); /* * issue the device reset, if enqueue failed, clean up the ioreq @@ -1576,6 +1827,9 @@ int fnic_device_reset(struct scsi_cmnd *sc) io_req->dr_done = NULL; goto fnic_device_reset_clean; } + spin_lock_irqsave(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_DEV_RST_PENDING; + spin_unlock_irqrestore(io_lock, flags); /* * Wait on the local completion for LUN reset. The io_req may be @@ -1588,12 +1842,13 @@ int fnic_device_reset(struct scsi_cmnd *sc) io_req = (struct fnic_io_req *)CMD_SP(sc); if (!io_req) { spin_unlock_irqrestore(io_lock, flags); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "io_req is null tag 0x%x sc 0x%p\n", tag, sc); goto fnic_device_reset_end; } io_req->dr_done = NULL; status = CMD_LR_STATUS(sc); - spin_unlock_irqrestore(io_lock, flags); /* * If lun reset not completed, bail out with failed. io_req @@ -1602,7 +1857,53 @@ int fnic_device_reset(struct scsi_cmnd *sc) if (status == FCPIO_INVALID_CODE) { FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Device reset timed out\n"); - goto fnic_device_reset_end; + CMD_FLAGS(sc) |= FNIC_DEV_RST_TIMED_OUT; + spin_unlock_irqrestore(io_lock, flags); + int_to_scsilun(sc->device->lun, &fc_lun); + /* + * Issue abort and terminate on the device reset request. + * If q'ing of the abort fails, retry issue it after a delay. + */ + while (1) { + spin_lock_irqsave(io_lock, flags); + if (CMD_FLAGS(sc) & FNIC_DEV_RST_TERM_ISSUED) { + spin_unlock_irqrestore(io_lock, flags); + break; + } + spin_unlock_irqrestore(io_lock, flags); + if (fnic_queue_abort_io_req(fnic, + tag | FNIC_TAG_DEV_RST, + FCPIO_ITMF_ABT_TASK_TERM, + fc_lun.scsi_lun, io_req)) { + wait_for_completion_timeout(&tm_done, + msecs_to_jiffies(FNIC_ABT_TERM_DELAY_TIMEOUT)); + } else { + spin_lock_irqsave(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; + io_req->abts_done = &tm_done; + spin_unlock_irqrestore(io_lock, flags); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "Abort and terminate issued on Device reset " + "tag 0x%x sc 0x%p\n", tag, sc); + break; + } + } + while (1) { + spin_lock_irqsave(io_lock, flags); + if (!(CMD_FLAGS(sc) & FNIC_DEV_RST_DONE)) { + spin_unlock_irqrestore(io_lock, flags); + wait_for_completion_timeout(&tm_done, + msecs_to_jiffies(FNIC_LUN_RESET_TIMEOUT)); + break; + } else { + io_req = (struct fnic_io_req *)CMD_SP(sc); + io_req->abts_done = NULL; + goto fnic_device_reset_clean; + } + } + } else { + spin_unlock_irqrestore(io_lock, flags); } /* Completed, but not successful, clean up the io_req, return fail */ @@ -1650,6 +1951,10 @@ fnic_device_reset_clean: } fnic_device_reset_end: + /* free tag if it is allocated */ + if (unlikely(tag_gen_flag)) + fnic_scsi_host_end_tag(fnic, sc); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Returning from device reset %s\n", (ret == SUCCESS) ? @@ -1735,7 +2040,15 @@ void fnic_scsi_abort_io(struct fc_lport *lp) DECLARE_COMPLETION_ONSTACK(remove_wait); /* Issue firmware reset for fnic, wait for reset to complete */ +retry_fw_reset: spin_lock_irqsave(&fnic->fnic_lock, flags); + if (unlikely(fnic->state == FNIC_IN_FC_TRANS_ETH_MODE)) { + /* fw reset is in progress, poll for its completion */ + spin_unlock_irqrestore(&fnic->fnic_lock, flags); + schedule_timeout(msecs_to_jiffies(100)); + goto retry_fw_reset; + } + fnic->remove_wait = &remove_wait; old_state = fnic->state; fnic->state = FNIC_IN_FC_TRANS_ETH_MODE; @@ -1776,7 +2089,14 @@ void fnic_scsi_cleanup(struct fc_lport *lp) struct fnic *fnic = lport_priv(lp); /* issue fw reset */ +retry_fw_reset: spin_lock_irqsave(&fnic->fnic_lock, flags); + if (unlikely(fnic->state == FNIC_IN_FC_TRANS_ETH_MODE)) { + /* fw reset is in progress, poll for its completion */ + spin_unlock_irqrestore(&fnic->fnic_lock, flags); + schedule_timeout(msecs_to_jiffies(100)); + goto retry_fw_reset; + } old_state = fnic->state; fnic->state = FNIC_IN_FC_TRANS_ETH_MODE; fnic_update_mac_locked(fnic, fnic->ctlr.ctl_src_addr); -- cgit v1.2.3-70-g09d2 From a0bf1ca27b644c1c4b1f0ea2d81f99471b2549e8 Mon Sep 17 00:00:00 2001 From: Hiral Patel Date: Tue, 12 Feb 2013 17:01:00 -0800 Subject: [SCSI] fnic: fnic driver may hit BUG_ON on device reset The issue was observed when LUN Reset is issued through IOCTL or sg_reset utility. fnic driver issues LUN RESET to firmware. On successful completion of device reset, driver cleans up all the pending IOs that were issued prior to device reset. These pending IOs are expected to be in ABTS_PENDING state. This works fine, when the device reset operation resulted from midlayer, but not when device reset was triggered from IOCTL path as the pending IOs were not in ABTS_PENDING state. execution path hits panic if the pending IO is not in ABTS_PENDING state. Changes: The fix replaces BUG_ON check in fnic_clean_pending_aborts() with marking pending IOs as ABTS_PENDING if they were not in ABTS_PENDING state and skips if they were already in ABTS_PENDING state. An extra check is added to validate the abort status of the commands after a delay of 2 * E_D_TOV using a helper function. The helper function returns 1 if it finds any pending IO in ABTS_PENDING state, belong to the LUN on which device reset was issued else 0. With this, device reset operation returns success only if the helper funciton returns 0, otherwise it returns failure. Other changes: - Removed code in fnic_clean_pending_aborts() that returns failure if it finds io_req NULL, instead of returning failure added code to continue with next io - Added device reset flags for debugging in fnic_terminate_rport_io, fnic_rport_exch_reset, and fnic_clean_pending_aborts Signed-off-by: Narsimhulu Musini Signed-off-by: Hiral Patel Signed-off-by: James Bottomley --- drivers/scsi/fnic/fnic.h | 2 + drivers/scsi/fnic/fnic_scsi.c | 121 +++++++++++++++++++++++++++++++++++++++--- 2 files changed, 116 insertions(+), 7 deletions(-) (limited to 'drivers/scsi/fnic/fnic_scsi.c') diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h index 63b35c8e40b..b8e6644ad23 100644 --- a/drivers/scsi/fnic/fnic.h +++ b/drivers/scsi/fnic/fnic.h @@ -303,6 +303,8 @@ const char *fnic_state_to_str(unsigned int state); void fnic_log_q_error(struct fnic *fnic); void fnic_handle_link_event(struct fnic *fnic); +int fnic_is_abts_pending(struct fnic *, struct scsi_cmnd *); + static inline int fnic_chk_state_flags_locked(struct fnic *fnic, unsigned long st_flags) { diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c index 2f46509f5b5..64830814da0 100644 --- a/drivers/scsi/fnic/fnic_scsi.c +++ b/drivers/scsi/fnic/fnic_scsi.c @@ -1271,7 +1271,8 @@ static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) spin_unlock_irqrestore(io_lock, flags); } else { spin_lock_irqsave(io_lock, flags); - CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; spin_unlock_irqrestore(io_lock, flags); } } @@ -1379,7 +1380,8 @@ void fnic_terminate_rport_io(struct fc_rport *rport) spin_unlock_irqrestore(io_lock, flags); } else { spin_lock_irqsave(io_lock, flags); - CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; spin_unlock_irqrestore(io_lock, flags); } } @@ -1592,7 +1594,7 @@ lr_io_req_end: static int fnic_clean_pending_aborts(struct fnic *fnic, struct scsi_cmnd *lr_sc) { - int tag; + int tag, abt_tag; struct fnic_io_req *io_req; spinlock_t *io_lock; unsigned long flags; @@ -1601,6 +1603,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, struct scsi_lun fc_lun; struct scsi_device *lun_dev = lr_sc->device; DECLARE_COMPLETION_ONSTACK(tm_done); + enum fnic_ioreq_state old_ioreq_state; for (tag = 0; tag < FNIC_MAX_IO_REQ; tag++) { sc = scsi_host_find_tag(fnic->lport->host, tag); @@ -1629,7 +1632,41 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, "Found IO in %s on lun\n", fnic_ioreq_state_to_str(CMD_STATE(sc))); - BUG_ON(CMD_STATE(sc) != FNIC_IOREQ_ABTS_PENDING); + if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { + spin_unlock_irqrestore(io_lock, flags); + continue; + } + if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "%s dev rst not pending sc 0x%p\n", __func__, + sc); + spin_unlock_irqrestore(io_lock, flags); + continue; + } + old_ioreq_state = CMD_STATE(sc); + /* + * Any pending IO issued prior to reset is expected to be + * in abts pending state, if not we need to set + * FNIC_IOREQ_ABTS_PENDING to indicate the IO is abort pending. + * When IO is completed, the IO will be handed over and + * handled in this function. + */ + CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; + + if (io_req->abts_done) + shost_printk(KERN_ERR, fnic->lport->host, + "%s: io_req->abts_done is set state is %s\n", + __func__, fnic_ioreq_state_to_str(CMD_STATE(sc))); + + BUG_ON(io_req->abts_done); + + abt_tag = tag; + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) { + abt_tag |= FNIC_TAG_DEV_RST; + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "%s: dev rst sc 0x%p\n", __func__, sc); + } CMD_ABTS_STATUS(sc) = FCPIO_INVALID_CODE; io_req->abts_done = &tm_done; @@ -1638,16 +1675,23 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, /* Now queue the abort command to firmware */ int_to_scsilun(sc->device->lun, &fc_lun); - if (fnic_queue_abort_io_req(fnic, tag, + if (fnic_queue_abort_io_req(fnic, abt_tag, FCPIO_ITMF_ABT_TASK_TERM, fc_lun.scsi_lun, io_req)) { spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); if (io_req) io_req->abts_done = NULL; + if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) + CMD_STATE(sc) = old_ioreq_state; spin_unlock_irqrestore(io_lock, flags); ret = 1; goto clean_pending_aborts_end; + } else { + spin_lock_irqsave(io_lock, flags); + if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) + CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + spin_unlock_irqrestore(io_lock, flags); } wait_for_completion_timeout(&tm_done, @@ -1659,8 +1703,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, io_req = (struct fnic_io_req *)CMD_SP(sc); if (!io_req) { spin_unlock_irqrestore(io_lock, flags); - ret = 1; - goto clean_pending_aborts_end; + continue; } io_req->abts_done = NULL; @@ -1678,6 +1721,12 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, mempool_free(io_req, fnic->io_req_pool); } + schedule_timeout(msecs_to_jiffies(2 * fnic->config.ed_tov)); + + /* walk again to check, if IOs are still pending in fw */ + if (fnic_is_abts_pending(fnic, lr_sc)) + ret = FAILED; + clean_pending_aborts_end: return ret; } @@ -2142,3 +2191,61 @@ call_fc_exch_mgr_reset: fc_exch_mgr_reset(lp, sid, did); } + +/* + * fnic_is_abts_pending() is a helper function that + * walks through tag map to check if there is any IOs pending,if there is one, + * then it returns 1 (true), otherwise 0 (false) + * if @lr_sc is non NULL, then it checks IOs specific to particular LUN, + * otherwise, it checks for all IOs. + */ +int fnic_is_abts_pending(struct fnic *fnic, struct scsi_cmnd *lr_sc) +{ + int tag; + struct fnic_io_req *io_req; + spinlock_t *io_lock; + unsigned long flags; + int ret = 0; + struct scsi_cmnd *sc; + struct scsi_device *lun_dev = NULL; + + if (lr_sc) + lun_dev = lr_sc->device; + + /* walk again to check, if IOs are still pending in fw */ + for (tag = 0; tag < FNIC_MAX_IO_REQ; tag++) { + sc = scsi_host_find_tag(fnic->lport->host, tag); + /* + * ignore this lun reset cmd or cmds that do not belong to + * this lun + */ + if (!sc || (lr_sc && (sc->device != lun_dev || sc == lr_sc))) + continue; + + io_lock = fnic_io_lock_hash(fnic, sc); + spin_lock_irqsave(io_lock, flags); + + io_req = (struct fnic_io_req *)CMD_SP(sc); + + if (!io_req || sc->device != lun_dev) { + spin_unlock_irqrestore(io_lock, flags); + continue; + } + + /* + * Found IO that is still pending with firmware and + * belongs to the LUN that we are resetting + */ + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "Found IO in %s on lun\n", + fnic_ioreq_state_to_str(CMD_STATE(sc))); + + if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { + spin_unlock_irqrestore(io_lock, flags); + ret = 1; + continue; + } + } + + return ret; +} -- cgit v1.2.3-70-g09d2 From 14eb5d905d16ecd33e5e3113eb44cfa2bb47e7d7 Mon Sep 17 00:00:00 2001 From: Hiral Patel Date: Tue, 12 Feb 2013 17:01:01 -0800 Subject: [SCSI] fnic: New debug flags and debug log messages Added new fnic debug flags for identifying IO state at every stage of IO while debugging and also added more log messages for better debugging capability. Signed-off-by: Sesidhar Baddela Signed-off-by: Hiral Patel Signed-off-by: James Bottomley --- drivers/scsi/fnic/fnic.h | 31 ++++++++--- drivers/scsi/fnic/fnic_io.h | 4 +- drivers/scsi/fnic/fnic_scsi.c | 118 +++++++++++++++++++++++++++++++++++++----- 3 files changed, 132 insertions(+), 21 deletions(-) (limited to 'drivers/scsi/fnic/fnic_scsi.c') diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h index b8e6644ad23..9c95a1ad56b 100644 --- a/drivers/scsi/fnic/fnic.h +++ b/drivers/scsi/fnic/fnic.h @@ -59,14 +59,29 @@ * Command flags to identify the type of command and for other future * use. */ -#define FNIC_NO_FLAGS 0 -#define FNIC_CDB_REQ BIT(1) /* All IOs with a valid CDB */ -#define FNIC_BLOCKING_REQ BIT(2) /* All blocking Requests */ -#define FNIC_DEVICE_RESET BIT(3) /* Device reset request */ -#define FNIC_DEV_RST_PENDING BIT(4) /* Device reset pending */ -#define FNIC_DEV_RST_TIMED_OUT BIT(5) /* Device reset timed out */ -#define FNIC_DEV_RST_TERM_ISSUED BIT(6) /* Device reset terminate */ -#define FNIC_DEV_RST_DONE BIT(7) /* Device reset done */ +#define FNIC_NO_FLAGS 0 +#define FNIC_IO_INITIALIZED BIT(0) +#define FNIC_IO_ISSUED BIT(1) +#define FNIC_IO_DONE BIT(2) +#define FNIC_IO_REQ_NULL BIT(3) +#define FNIC_IO_ABTS_PENDING BIT(4) +#define FNIC_IO_ABORTED BIT(5) +#define FNIC_IO_ABTS_ISSUED BIT(6) +#define FNIC_IO_TERM_ISSUED BIT(7) +#define FNIC_IO_INTERNAL_TERM_ISSUED BIT(8) +#define FNIC_IO_ABT_TERM_DONE BIT(9) +#define FNIC_IO_ABT_TERM_REQ_NULL BIT(10) +#define FNIC_IO_ABT_TERM_TIMED_OUT BIT(11) +#define FNIC_DEVICE_RESET BIT(12) /* Device reset request */ +#define FNIC_DEV_RST_ISSUED BIT(13) +#define FNIC_DEV_RST_TIMED_OUT BIT(14) +#define FNIC_DEV_RST_ABTS_ISSUED BIT(15) +#define FNIC_DEV_RST_TERM_ISSUED BIT(16) +#define FNIC_DEV_RST_DONE BIT(17) +#define FNIC_DEV_RST_REQ_NULL BIT(18) +#define FNIC_DEV_RST_ABTS_DONE BIT(19) +#define FNIC_DEV_RST_TERM_DONE BIT(20) +#define FNIC_DEV_RST_ABTS_PENDING BIT(21) /* * Usage of the scsi_cmnd scratchpad. diff --git a/drivers/scsi/fnic/fnic_io.h b/drivers/scsi/fnic/fnic_io.h index 3455c34ada4..c35b8f1889e 100644 --- a/drivers/scsi/fnic/fnic_io.h +++ b/drivers/scsi/fnic/fnic_io.h @@ -45,7 +45,8 @@ enum fnic_sgl_list_type { }; enum fnic_ioreq_state { - FNIC_IOREQ_CMD_PENDING = 0, + FNIC_IOREQ_NOT_INITED = 0, + FNIC_IOREQ_CMD_PENDING, FNIC_IOREQ_ABTS_PENDING, FNIC_IOREQ_ABTS_COMPLETE, FNIC_IOREQ_CMD_COMPLETE, @@ -60,6 +61,7 @@ struct fnic_io_req { u8 sgl_type; /* device DMA descriptor list type */ u8 io_completed:1; /* set to 1 when fw completes IO */ u32 port_id; /* remote port DID */ + unsigned long start_time; /* in jiffies */ struct completion *abts_done; /* completion for abts */ struct completion *dr_done; /* completion for device reset */ }; diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c index 64830814da0..7cb65330912 100644 --- a/drivers/scsi/fnic/fnic_scsi.c +++ b/drivers/scsi/fnic/fnic_scsi.c @@ -47,6 +47,7 @@ const char *fnic_state_str[] = { }; static const char *fnic_ioreq_state_str[] = { + [FNIC_IOREQ_NOT_INITED] = "FNIC_IOREQ_NOT_INITED", [FNIC_IOREQ_CMD_PENDING] = "FNIC_IOREQ_CMD_PENDING", [FNIC_IOREQ_ABTS_PENDING] = "FNIC_IOREQ_ABTS_PENDING", [FNIC_IOREQ_ABTS_COMPLETE] = "FNIC_IOREQ_ABTS_COMPLETE", @@ -349,6 +350,8 @@ static inline int fnic_queue_wq_copy_desc(struct fnic *fnic, if (unlikely(!vnic_wq_copy_desc_avail(wq))) { spin_unlock_irqrestore(&fnic->wq_copy_lock[0], intr_flags); + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "fnic_queue_wq_copy_desc failure - no descriptors\n"); return SCSI_MLQUEUE_HOST_BUSY; } @@ -420,7 +423,8 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ * caller disabling them. */ spin_unlock(lp->host->host_lock); - CMD_FLAGS(sc) = FNIC_CDB_REQ; + CMD_STATE(sc) = FNIC_IOREQ_NOT_INITED; + CMD_FLAGS(sc) = FNIC_NO_FLAGS; /* Get a new io_req for this SCSI IO */ io_req = mempool_alloc(fnic->io_req_pool, GFP_ATOMIC); @@ -467,8 +471,10 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ /* initialize rest of io_req */ io_req->port_id = rport->port_id; + io_req->start_time = jiffies; CMD_STATE(sc) = FNIC_IOREQ_CMD_PENDING; CMD_SP(sc) = (char *)io_req; + CMD_FLAGS(sc) |= FNIC_IO_INITIALIZED; sc->scsi_done = done; /* create copy wq desc and enqueue it */ @@ -490,6 +496,9 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); } + } else { + /* REVISIT: Use per IO lock in the final code */ + CMD_FLAGS(sc) |= FNIC_IO_ISSUED; } out: atomic_dec(&fnic->in_flight); @@ -694,10 +703,12 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, struct scsi_cmnd *sc; unsigned long flags; spinlock_t *io_lock; + unsigned long start_time; /* Decode the cmpl description to get the io_req id */ fcpio_header_dec(&desc->hdr, &type, &hdr_status, &tag); fcpio_tag_id_dec(&tag, &id); + icmnd_cmpl = &desc->u.icmnd_cmpl; if (id >= FNIC_MAX_IO_REQ) { shost_printk(KERN_ERR, fnic->lport->host, @@ -708,17 +719,28 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, sc = scsi_host_find_tag(fnic->lport->host, id); WARN_ON_ONCE(!sc); - if (!sc) + if (!sc) { + shost_printk(KERN_ERR, fnic->lport->host, + "icmnd_cmpl sc is null - " + "hdr status = %s tag = 0x%x desc = 0x%p\n", + fnic_fcpio_status_to_str(hdr_status), id, desc); return; + } io_lock = fnic_io_lock_hash(fnic, sc); spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); WARN_ON_ONCE(!io_req); if (!io_req) { + CMD_FLAGS(sc) |= FNIC_IO_REQ_NULL; spin_unlock_irqrestore(io_lock, flags); + shost_printk(KERN_ERR, fnic->lport->host, + "icmnd_cmpl io_req is null - " + "hdr status = %s tag = 0x%x sc 0x%p\n", + fnic_fcpio_status_to_str(hdr_status), id, sc); return; } + start_time = io_req->start_time; /* firmware completed the io */ io_req->io_completed = 1; @@ -729,6 +751,28 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, */ if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABTS_PENDING; + switch (hdr_status) { + case FCPIO_SUCCESS: + CMD_FLAGS(sc) |= FNIC_IO_DONE; + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "icmnd_cmpl ABTS pending hdr status = %s " + "sc 0x%p scsi_status %x residual %d\n", + fnic_fcpio_status_to_str(hdr_status), sc, + icmnd_cmpl->scsi_status, + icmnd_cmpl->residual); + break; + case FCPIO_ABORTED: + CMD_FLAGS(sc) |= FNIC_IO_ABORTED; + break; + default: + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "icmnd_cmpl abts pending " + "hdr status = %s tag = 0x%x sc = 0x%p\n", + fnic_fcpio_status_to_str(hdr_status), + id, sc); + break; + } return; } @@ -812,6 +856,7 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, /* Break link with the SCSI command */ CMD_SP(sc) = NULL; + CMD_FLAGS(sc) |= FNIC_IO_DONE; spin_unlock_irqrestore(io_lock, flags); @@ -848,6 +893,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, struct fnic_io_req *io_req; unsigned long flags; spinlock_t *io_lock; + unsigned long start_time; fcpio_header_dec(&desc->hdr, &type, &hdr_status, &tag); fcpio_tag_id_dec(&tag, &id); @@ -861,17 +907,26 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, sc = scsi_host_find_tag(fnic->lport->host, id & FNIC_TAG_MASK); WARN_ON_ONCE(!sc); - if (!sc) + if (!sc) { + shost_printk(KERN_ERR, fnic->lport->host, + "itmf_cmpl sc is null - hdr status = %s tag = 0x%x\n", + fnic_fcpio_status_to_str(hdr_status), id); return; - + } io_lock = fnic_io_lock_hash(fnic, sc); spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); WARN_ON_ONCE(!io_req); if (!io_req) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_REQ_NULL; + shost_printk(KERN_ERR, fnic->lport->host, + "itmf_cmpl io_req is null - " + "hdr status = %s tag = 0x%x sc 0x%p\n", + fnic_fcpio_status_to_str(hdr_status), id, sc); return; } + start_time = io_req->start_time; if ((id & FNIC_TAG_ABORT) && (id & FNIC_TAG_DEV_RST)) { /* Abort and terminate completion of device reset req */ @@ -895,6 +950,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, CMD_STATE(sc) = FNIC_IOREQ_ABTS_COMPLETE; CMD_ABTS_STATUS(sc) = hdr_status; + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_DONE; FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "abts cmpl recd. id %d status %s\n", (int)(id & FNIC_TAG_MASK), @@ -927,6 +983,7 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, CMD_LR_STATUS(sc) = hdr_status; if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_DEV_RST_ABTS_PENDING; FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Terminate pending " "dev reset cmpl recd. id %d status %s\n", @@ -1032,6 +1089,7 @@ static void fnic_cleanup_io(struct fnic *fnic, int exclude_id) unsigned long flags = 0; struct scsi_cmnd *sc; spinlock_t *io_lock; + unsigned long start_time = 0; for (i = 0; i < FNIC_MAX_IO_REQ; i++) { if (i == exclude_id) @@ -1074,6 +1132,7 @@ static void fnic_cleanup_io(struct fnic *fnic, int exclude_id) * If there is a scsi_cmnd associated with this io_req, then * free the corresponding state */ + start_time = io_req->start_time; fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); @@ -1097,6 +1156,7 @@ void fnic_wq_copy_cleanup_handler(struct vnic_wq_copy *wq, struct scsi_cmnd *sc; unsigned long flags; spinlock_t *io_lock; + unsigned long start_time = 0; /* get the tag reference */ fcpio_tag_id_dec(&desc->hdr.tag, &id); @@ -1126,6 +1186,7 @@ void fnic_wq_copy_cleanup_handler(struct vnic_wq_copy *wq, spin_unlock_irqrestore(io_lock, flags); + start_time = io_req->start_time; fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); @@ -1163,7 +1224,7 @@ static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag, if (!vnic_wq_copy_desc_avail(wq)) { spin_unlock_irqrestore(&fnic->wq_copy_lock[0], flags); atomic_dec(&fnic->in_flight); - shost_printk(KERN_DEBUG, fnic->lport->host, + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "fnic_queue_abort_io_req: failure: no descriptors\n"); return 1; } @@ -1213,7 +1274,7 @@ static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) } if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && - (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_ISSUED))) { FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "fnic_rport_exch_reset dev rst not pending sc 0x%p\n", sc); @@ -1236,6 +1297,13 @@ static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) fnic_ioreq_state_to_str(CMD_STATE(sc))); } + if (!(CMD_FLAGS(sc) & FNIC_IO_ISSUED)) { + shost_printk(KERN_ERR, fnic->lport->host, + "rport_exch_reset " + "IO not yet issued %p tag 0x%x flags " + "%x state %d\n", + sc, tag, CMD_FLAGS(sc), CMD_STATE(sc)); + } old_ioreq_state = CMD_STATE(sc); CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; CMD_ABTS_STATUS(sc) = FCPIO_INVALID_CODE; @@ -1273,6 +1341,8 @@ static void fnic_rport_exch_reset(struct fnic *fnic, u32 port_id) spin_lock_irqsave(io_lock, flags); if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + else + CMD_FLAGS(sc) |= FNIC_IO_INTERNAL_TERM_ISSUED; spin_unlock_irqrestore(io_lock, flags); } } @@ -1324,7 +1394,7 @@ void fnic_terminate_rport_io(struct fc_rport *rport) } if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && - (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_ISSUED))) { FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "fnic_terminate_rport_io dev rst not pending sc 0x%p\n", sc); @@ -1345,6 +1415,13 @@ void fnic_terminate_rport_io(struct fc_rport *rport) "state is %s\n", fnic_ioreq_state_to_str(CMD_STATE(sc))); } + if (!(CMD_FLAGS(sc) & FNIC_IO_ISSUED)) { + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "fnic_terminate_rport_io " + "IO not yet issued %p tag 0x%x flags " + "%x state %d\n", + sc, tag, CMD_FLAGS(sc), CMD_STATE(sc)); + } old_ioreq_state = CMD_STATE(sc); CMD_STATE(sc) = FNIC_IOREQ_ABTS_PENDING; CMD_ABTS_STATUS(sc) = FCPIO_INVALID_CODE; @@ -1382,6 +1459,8 @@ void fnic_terminate_rport_io(struct fc_rport *rport) spin_lock_irqsave(io_lock, flags); if (CMD_FLAGS(sc) & FNIC_DEVICE_RESET) CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; + else + CMD_FLAGS(sc) |= FNIC_IO_INTERNAL_TERM_ISSUED; spin_unlock_irqrestore(io_lock, flags); } } @@ -1401,8 +1480,9 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) struct fc_rport *rport; spinlock_t *io_lock; unsigned long flags; + unsigned long start_time = 0; int ret = SUCCESS; - u32 task_req; + u32 task_req = 0; struct scsi_lun fc_lun; int tag; DECLARE_COMPLETION_ONSTACK(tm_done); @@ -1489,6 +1569,10 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) ret = FAILED; goto fnic_abort_cmd_end; } + if (task_req == FCPIO_ITMF_ABT_TASK) + CMD_FLAGS(sc) |= FNIC_IO_ABTS_ISSUED; + else + CMD_FLAGS(sc) |= FNIC_IO_TERM_ISSUED; /* * We queued an abort IO, wait for its completion. @@ -1507,6 +1591,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) io_req = (struct fnic_io_req *)CMD_SP(sc); if (!io_req) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_REQ_NULL; ret = FAILED; goto fnic_abort_cmd_end; } @@ -1515,6 +1600,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) /* fw did not complete abort, timed out */ if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_TIMED_OUT; ret = FAILED; goto fnic_abort_cmd_end; } @@ -1530,12 +1616,13 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) spin_unlock_irqrestore(io_lock, flags); + start_time = io_req->start_time; fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); fnic_abort_cmd_end: FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, - "Returning from abort cmd %s\n", + "Returning from abort cmd type %x %s\n", task_req, (ret == SUCCESS) ? "SUCCESS" : "FAILED"); return ret; @@ -1566,6 +1653,8 @@ static inline int fnic_queue_dr_io_req(struct fnic *fnic, free_wq_copy_descs(fnic, wq); if (!vnic_wq_copy_desc_avail(wq)) { + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, + "queue_dr_io_req failure - no descriptors\n"); ret = -EAGAIN; goto lr_io_req_end; } @@ -1637,7 +1726,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, continue; } if ((CMD_FLAGS(sc) & FNIC_DEVICE_RESET) && - (!(CMD_FLAGS(sc) & FNIC_DEV_RST_PENDING))) { + (!(CMD_FLAGS(sc) & FNIC_DEV_RST_ISSUED))) { FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, "%s dev rst not pending sc 0x%p\n", __func__, sc); @@ -1693,6 +1782,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, CMD_FLAGS(sc) |= FNIC_DEV_RST_TERM_ISSUED; spin_unlock_irqrestore(io_lock, flags); } + CMD_FLAGS(sc) |= FNIC_IO_INTERNAL_TERM_ISSUED; wait_for_completion_timeout(&tm_done, msecs_to_jiffies @@ -1703,6 +1793,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, io_req = (struct fnic_io_req *)CMD_SP(sc); if (!io_req) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_REQ_NULL; continue; } @@ -1711,6 +1802,7 @@ static int fnic_clean_pending_aborts(struct fnic *fnic, /* if abort is still pending with fw, fail */ if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { spin_unlock_irqrestore(io_lock, flags); + CMD_FLAGS(sc) |= FNIC_IO_ABT_TERM_DONE; ret = 1; goto clean_pending_aborts_end; } @@ -1805,6 +1897,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) int ret = FAILED; spinlock_t *io_lock; unsigned long flags; + unsigned long start_time = 0; struct scsi_lun fc_lun; int tag; DECLARE_COMPLETION_ONSTACK(tm_done); @@ -1830,7 +1923,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) if (fc_remote_port_chkready(rport)) goto fnic_device_reset_end; - CMD_FLAGS(sc) = (FNIC_DEVICE_RESET | FNIC_BLOCKING_REQ); + CMD_FLAGS(sc) = FNIC_DEVICE_RESET; /* Allocate tag if not present */ tag = sc->request->tag; @@ -1877,7 +1970,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) goto fnic_device_reset_clean; } spin_lock_irqsave(io_lock, flags); - CMD_FLAGS(sc) |= FNIC_DEV_RST_PENDING; + CMD_FLAGS(sc) |= FNIC_DEV_RST_ISSUED; spin_unlock_irqrestore(io_lock, flags); /* @@ -1995,6 +2088,7 @@ fnic_device_reset_clean: spin_unlock_irqrestore(io_lock, flags); if (io_req) { + start_time = io_req->start_time; fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); } -- cgit v1.2.3-70-g09d2 From 4d7007b49d523d8f954ae047118d82c130f673ce Mon Sep 17 00:00:00 2001 From: Hiral Patel Date: Tue, 12 Feb 2013 17:01:02 -0800 Subject: [SCSI] fnic: Fnic Trace Utility Fnic Trace utility is a tracing functionality built directly into fnic driver to trace events. The benefit that trace buffer brings to fnic driver is the ability to see what it happening inside the fnic driver. It also provides the capability to trace every IO event inside fnic driver to debug panics, hangs and potentially IO corruption issues. This feature makes it easy to find problems in fnic driver and it also helps in tracking down strange bugs in a more manageable way. Trace buffer is shared across all fnic instances for this implementation. Signed-off-by: Hiral Patel Signed-off-by: James Bottomley --- drivers/scsi/fnic/Makefile | 2 + drivers/scsi/fnic/fnic.h | 1 + drivers/scsi/fnic/fnic_debugfs.c | 314 +++++++++++++++++++++++++++++++++++++++ drivers/scsi/fnic/fnic_main.c | 14 ++ drivers/scsi/fnic/fnic_scsi.c | 120 +++++++++++++-- drivers/scsi/fnic/fnic_trace.c | 273 ++++++++++++++++++++++++++++++++++ drivers/scsi/fnic/fnic_trace.h | 90 +++++++++++ 7 files changed, 803 insertions(+), 11 deletions(-) create mode 100644 drivers/scsi/fnic/fnic_debugfs.c create mode 100644 drivers/scsi/fnic/fnic_trace.c create mode 100644 drivers/scsi/fnic/fnic_trace.h (limited to 'drivers/scsi/fnic/fnic_scsi.c') diff --git a/drivers/scsi/fnic/Makefile b/drivers/scsi/fnic/Makefile index 37c3440bc17..383598fadf0 100644 --- a/drivers/scsi/fnic/Makefile +++ b/drivers/scsi/fnic/Makefile @@ -7,6 +7,8 @@ fnic-y := \ fnic_res.o \ fnic_fcs.o \ fnic_scsi.o \ + fnic_trace.o \ + fnic_debugfs.o \ vnic_cq.o \ vnic_dev.o \ vnic_intr.o \ diff --git a/drivers/scsi/fnic/fnic.h b/drivers/scsi/fnic/fnic.h index 9c95a1ad56b..98436c36303 100644 --- a/drivers/scsi/fnic/fnic.h +++ b/drivers/scsi/fnic/fnic.h @@ -26,6 +26,7 @@ #include #include "fnic_io.h" #include "fnic_res.h" +#include "fnic_trace.h" #include "vnic_dev.h" #include "vnic_wq.h" #include "vnic_rq.h" diff --git a/drivers/scsi/fnic/fnic_debugfs.c b/drivers/scsi/fnic/fnic_debugfs.c new file mode 100644 index 00000000000..adc1f7f471f --- /dev/null +++ b/drivers/scsi/fnic/fnic_debugfs.c @@ -0,0 +1,314 @@ +/* + * Copyright 2012 Cisco Systems, Inc. All rights reserved. + * + * This program is free software; you may redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; version 2 of the License. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, + * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF + * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND + * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS + * BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN + * ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN + * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE + * SOFTWARE. + */ + +#include +#include +#include +#include "fnic.h" + +static struct dentry *fnic_trace_debugfs_root; +static struct dentry *fnic_trace_debugfs_file; +static struct dentry *fnic_trace_enable; + +/* + * fnic_trace_ctrl_open - Open the trace_enable file + * @inode: The inode pointer. + * @file: The file pointer to attach the trace enable/disable flag. + * + * Description: + * This routine opens a debugsfs file trace_enable. + * + * Returns: + * This function returns zero if successful. + */ +static int fnic_trace_ctrl_open(struct inode *inode, struct file *filp) +{ + filp->private_data = inode->i_private; + return 0; +} + +/* + * fnic_trace_ctrl_read - Read a trace_enable debugfs file + * @filp: The file pointer to read from. + * @ubuf: The buffer to copy the data to. + * @cnt: The number of bytes to read. + * @ppos: The position in the file to start reading from. + * + * Description: + * This routine reads value of variable fnic_tracing_enabled + * and stores into local @buf. It will start reading file at @ppos and + * copy up to @cnt of data to @ubuf from @buf. + * + * Returns: + * This function returns the amount of data that was read. + */ +static ssize_t fnic_trace_ctrl_read(struct file *filp, + char __user *ubuf, + size_t cnt, loff_t *ppos) +{ + char buf[64]; + int len; + len = sprintf(buf, "%u\n", fnic_tracing_enabled); + + return simple_read_from_buffer(ubuf, cnt, ppos, buf, len); +} + +/* + * fnic_trace_ctrl_write - Write to trace_enable debugfs file + * @filp: The file pointer to write from. + * @ubuf: The buffer to copy the data from. + * @cnt: The number of bytes to write. + * @ppos: The position in the file to start writing to. + * + * Description: + * This routine writes data from user buffer @ubuf to buffer @buf and + * sets fnic_tracing_enabled value as per user input. + * + * Returns: + * This function returns the amount of data that was written. + */ +static ssize_t fnic_trace_ctrl_write(struct file *filp, + const char __user *ubuf, + size_t cnt, loff_t *ppos) +{ + char buf[64]; + unsigned long val; + int ret; + + if (cnt >= sizeof(buf)) + return -EINVAL; + + if (copy_from_user(&buf, ubuf, cnt)) + return -EFAULT; + + buf[cnt] = 0; + + ret = kstrtoul(buf, 10, &val); + if (ret < 0) + return ret; + + fnic_tracing_enabled = val; + (*ppos)++; + + return cnt; +} + +/* + * fnic_trace_debugfs_open - Open the fnic trace log + * @inode: The inode pointer + * @file: The file pointer to attach the log output + * + * Description: + * This routine is the entry point for the debugfs open file operation. + * It allocates the necessary buffer for the log, fills the buffer from + * the in-memory log and then returns a pointer to that log in + * the private_data field in @file. + * + * Returns: + * This function returns zero if successful. On error it will return + * a negative error value. + */ +static int fnic_trace_debugfs_open(struct inode *inode, + struct file *file) +{ + fnic_dbgfs_t *fnic_dbg_prt; + fnic_dbg_prt = kzalloc(sizeof(fnic_dbgfs_t), GFP_KERNEL); + if (!fnic_dbg_prt) + return -ENOMEM; + + fnic_dbg_prt->buffer = vmalloc((3*(trace_max_pages * PAGE_SIZE))); + if (!fnic_dbg_prt->buffer) { + kfree(fnic_dbg_prt); + return -ENOMEM; + } + memset((void *)fnic_dbg_prt->buffer, 0, + (3*(trace_max_pages * PAGE_SIZE))); + fnic_dbg_prt->buffer_len = fnic_get_trace_data(fnic_dbg_prt); + file->private_data = fnic_dbg_prt; + return 0; +} + +/* + * fnic_trace_debugfs_lseek - Seek through a debugfs file + * @file: The file pointer to seek through. + * @offset: The offset to seek to or the amount to seek by. + * @howto: Indicates how to seek. + * + * Description: + * This routine is the entry point for the debugfs lseek file operation. + * The @howto parameter indicates whether @offset is the offset to directly + * seek to, or if it is a value to seek forward or reverse by. This function + * figures out what the new offset of the debugfs file will be and assigns + * that value to the f_pos field of @file. + * + * Returns: + * This function returns the new offset if successful and returns a negative + * error if unable to process the seek. + */ +static loff_t fnic_trace_debugfs_lseek(struct file *file, + loff_t offset, + int howto) +{ + fnic_dbgfs_t *fnic_dbg_prt = file->private_data; + loff_t pos = -1; + + switch (howto) { + case 0: + pos = offset; + break; + case 1: + pos = file->f_pos + offset; + break; + case 2: + pos = fnic_dbg_prt->buffer_len - offset; + } + return (pos < 0 || pos > fnic_dbg_prt->buffer_len) ? + -EINVAL : (file->f_pos = pos); +} + +/* + * fnic_trace_debugfs_read - Read a debugfs file + * @file: The file pointer to read from. + * @ubuf: The buffer to copy the data to. + * @nbytes: The number of bytes to read. + * @pos: The position in the file to start reading from. + * + * Description: + * This routine reads data from the buffer indicated in the private_data + * field of @file. It will start reading at @pos and copy up to @nbytes of + * data to @ubuf. + * + * Returns: + * This function returns the amount of data that was read (this could be + * less than @nbytes if the end of the file was reached). + */ +static ssize_t fnic_trace_debugfs_read(struct file *file, + char __user *ubuf, + size_t nbytes, + loff_t *pos) +{ + fnic_dbgfs_t *fnic_dbg_prt = file->private_data; + int rc = 0; + rc = simple_read_from_buffer(ubuf, nbytes, pos, + fnic_dbg_prt->buffer, + fnic_dbg_prt->buffer_len); + return rc; +} + +/* + * fnic_trace_debugfs_release - Release the buffer used to store + * debugfs file data + * @inode: The inode pointer + * @file: The file pointer that contains the buffer to release + * + * Description: + * This routine frees the buffer that was allocated when the debugfs + * file was opened. + * + * Returns: + * This function returns zero. + */ +static int fnic_trace_debugfs_release(struct inode *inode, + struct file *file) +{ + fnic_dbgfs_t *fnic_dbg_prt = file->private_data; + + vfree(fnic_dbg_prt->buffer); + kfree(fnic_dbg_prt); + return 0; +} + +static const struct file_operations fnic_trace_ctrl_fops = { + .owner = THIS_MODULE, + .open = fnic_trace_ctrl_open, + .read = fnic_trace_ctrl_read, + .write = fnic_trace_ctrl_write, +}; + +static const struct file_operations fnic_trace_debugfs_fops = { + .owner = THIS_MODULE, + .open = fnic_trace_debugfs_open, + .llseek = fnic_trace_debugfs_lseek, + .read = fnic_trace_debugfs_read, + .release = fnic_trace_debugfs_release, +}; + +/* + * fnic_trace_debugfs_init - Initialize debugfs for fnic trace logging + * + * Description: + * When Debugfs is configured this routine sets up the fnic debugfs + * file system. If not already created, this routine will create the + * fnic directory. It will create file trace to log fnic trace buffer + * output into debugfs and it will also create file trace_enable to + * control enable/disable of trace logging into trace buffer. + */ +int fnic_trace_debugfs_init(void) +{ + int rc = -1; + fnic_trace_debugfs_root = debugfs_create_dir("fnic", NULL); + if (!fnic_trace_debugfs_root) { + printk(KERN_DEBUG "Cannot create debugfs root\n"); + return rc; + } + fnic_trace_enable = debugfs_create_file("tracing_enable", + S_IFREG|S_IRUGO|S_IWUSR, + fnic_trace_debugfs_root, + NULL, &fnic_trace_ctrl_fops); + + if (!fnic_trace_enable) { + printk(KERN_DEBUG "Cannot create trace_enable file" + " under debugfs"); + return rc; + } + + fnic_trace_debugfs_file = debugfs_create_file("trace", + S_IFREG|S_IRUGO|S_IWUSR, + fnic_trace_debugfs_root, + NULL, + &fnic_trace_debugfs_fops); + + if (!fnic_trace_debugfs_file) { + printk(KERN_DEBUG "Cannot create trace file under debugfs"); + return rc; + } + rc = 0; + return rc; +} + +/* + * fnic_trace_debugfs_terminate - Tear down debugfs infrastructure + * + * Description: + * When Debugfs is configured this routine removes debugfs file system + * elements that are specific to fnic trace logging. + */ +void fnic_trace_debugfs_terminate(void) +{ + if (fnic_trace_debugfs_file) { + debugfs_remove(fnic_trace_debugfs_file); + fnic_trace_debugfs_file = NULL; + } + if (fnic_trace_enable) { + debugfs_remove(fnic_trace_enable); + fnic_trace_enable = NULL; + } + if (fnic_trace_debugfs_root) { + debugfs_remove(fnic_trace_debugfs_root); + fnic_trace_debugfs_root = NULL; + } +} diff --git a/drivers/scsi/fnic/fnic_main.c b/drivers/scsi/fnic/fnic_main.c index fcecbb7281a..d601ac543c5 100644 --- a/drivers/scsi/fnic/fnic_main.c +++ b/drivers/scsi/fnic/fnic_main.c @@ -68,6 +68,10 @@ unsigned int fnic_log_level; module_param(fnic_log_level, int, S_IRUGO|S_IWUSR); MODULE_PARM_DESC(fnic_log_level, "bit mask of fnic logging levels"); +unsigned int fnic_trace_max_pages = 16; +module_param(fnic_trace_max_pages, uint, S_IRUGO|S_IWUSR); +MODULE_PARM_DESC(fnic_trace_max_pages, "Total allocated memory pages " + "for fnic trace buffer"); static struct libfc_function_template fnic_transport_template = { .frame_send = fnic_send, @@ -861,6 +865,14 @@ static int __init fnic_init_module(void) printk(KERN_INFO PFX "%s, ver %s\n", DRV_DESCRIPTION, DRV_VERSION); + /* Allocate memory for trace buffer */ + err = fnic_trace_buf_init(); + if (err < 0) { + printk(KERN_ERR PFX "Trace buffer initialization Failed " + "Fnic Tracing utility is disabled\n"); + fnic_trace_free(); + } + /* Create a cache for allocation of default size sgls */ len = sizeof(struct fnic_dflt_sgl_list); fnic_sgl_cache[FNIC_SGL_CACHE_DFLT] = kmem_cache_create @@ -931,6 +943,7 @@ err_create_fnic_ioreq_slab: err_create_fnic_sgl_slab_max: kmem_cache_destroy(fnic_sgl_cache[FNIC_SGL_CACHE_DFLT]); err_create_fnic_sgl_slab_dflt: + fnic_trace_free(); return err; } @@ -942,6 +955,7 @@ static void __exit fnic_cleanup_module(void) kmem_cache_destroy(fnic_sgl_cache[FNIC_SGL_CACHE_DFLT]); kmem_cache_destroy(fnic_io_req_cache); fc_release_transport(fnic_fc_transport); + fnic_trace_free(); } module_init(fnic_init_module); diff --git a/drivers/scsi/fnic/fnic_scsi.c b/drivers/scsi/fnic/fnic_scsi.c index 7cb65330912..be99e7549d8 100644 --- a/drivers/scsi/fnic/fnic_scsi.c +++ b/drivers/scsi/fnic/fnic_scsi.c @@ -393,11 +393,12 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ { struct fc_lport *lp = shost_priv(sc->device->host); struct fc_rport *rport; - struct fnic_io_req *io_req; + struct fnic_io_req *io_req = NULL; struct fnic *fnic = lport_priv(lp); struct vnic_wq_copy *wq; int ret; - int sg_count; + u64 cmd_trace; + int sg_count = 0; unsigned long flags; unsigned long ptr; @@ -437,6 +438,9 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ /* Map the data buffer */ sg_count = scsi_dma_map(sc); if (sg_count < 0) { + FNIC_TRACE(fnic_queuecommand, sc->device->host->host_no, + sc->request->tag, sc, 0, sc->cmnd[0], + sg_count, CMD_STATE(sc)); mempool_free(io_req, fnic->io_req_pool); goto out; } @@ -486,7 +490,9 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ * refetch the pointer under the lock. */ spinlock_t *io_lock = fnic_io_lock_hash(fnic, sc); - + FNIC_TRACE(fnic_queuecommand, sc->device->host->host_no, + sc->request->tag, sc, 0, 0, 0, + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); spin_lock_irqsave(io_lock, flags); io_req = (struct fnic_io_req *)CMD_SP(sc); CMD_SP(sc) = NULL; @@ -501,6 +507,15 @@ static int fnic_queuecommand_lck(struct scsi_cmnd *sc, void (*done)(struct scsi_ CMD_FLAGS(sc) |= FNIC_IO_ISSUED; } out: + cmd_trace = ((u64)sc->cmnd[0] << 56 | (u64)sc->cmnd[7] << 40 | + (u64)sc->cmnd[8] << 32 | (u64)sc->cmnd[2] << 24 | + (u64)sc->cmnd[3] << 16 | (u64)sc->cmnd[4] << 8 | + sc->cmnd[5]); + + FNIC_TRACE(fnic_queuecommand, sc->device->host->host_no, + sc->request->tag, sc, io_req, + sg_count, cmd_trace, + (((u64)CMD_FLAGS(sc) >> 32) | CMD_STATE(sc))); atomic_dec(&fnic->in_flight); /* acquire host lock before returning to SCSI */ spin_lock(lp->host->host_lock); @@ -674,6 +689,7 @@ static inline void fnic_fcpio_ack_handler(struct fnic *fnic, struct vnic_wq_copy *wq; u16 request_out = desc->u.ack.request_out; unsigned long flags; + u64 *ox_id_tag = (u64 *)(void *)desc; /* mark the ack state */ wq = &fnic->wq_copy[cq_index - fnic->raw_wq_count - fnic->rq_count]; @@ -684,6 +700,9 @@ static inline void fnic_fcpio_ack_handler(struct fnic *fnic, fnic->fw_ack_recd[0] = 1; } spin_unlock_irqrestore(&fnic->wq_copy_lock[0], flags); + FNIC_TRACE(fnic_fcpio_ack_handler, + fnic->lport->host->host_no, 0, 0, ox_id_tag[2], ox_id_tag[3], + ox_id_tag[4], ox_id_tag[5]); } /* @@ -703,6 +722,7 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, struct scsi_cmnd *sc; unsigned long flags; spinlock_t *io_lock; + u64 cmd_trace; unsigned long start_time; /* Decode the cmpl description to get the io_req id */ @@ -724,6 +744,14 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, "icmnd_cmpl sc is null - " "hdr status = %s tag = 0x%x desc = 0x%p\n", fnic_fcpio_status_to_str(hdr_status), id, desc); + FNIC_TRACE(fnic_fcpio_icmnd_cmpl_handler, + fnic->lport->host->host_no, id, + ((u64)icmnd_cmpl->_resvd0[1] << 16 | + (u64)icmnd_cmpl->_resvd0[0]), + ((u64)hdr_status << 16 | + (u64)icmnd_cmpl->scsi_status << 8 | + (u64)icmnd_cmpl->flags), desc, + (u64)icmnd_cmpl->residual, 0); return; } @@ -864,6 +892,20 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, mempool_free(io_req, fnic->io_req_pool); + cmd_trace = ((u64)hdr_status << 56) | + (u64)icmnd_cmpl->scsi_status << 48 | + (u64)icmnd_cmpl->flags << 40 | (u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]; + + FNIC_TRACE(fnic_fcpio_icmnd_cmpl_handler, + sc->device->host->host_no, id, sc, + ((u64)icmnd_cmpl->_resvd0[1] << 56 | + (u64)icmnd_cmpl->_resvd0[0] << 48 | + jiffies_to_msecs(jiffies - start_time)), + desc, cmd_trace, + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); + if (sc->sc_data_direction == DMA_FROM_DEVICE) { fnic->lport->host_stats.fcp_input_requests++; fnic->fcp_input_bytes += xfer_len; @@ -876,7 +918,6 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, /* Call SCSI completion function to complete the IO */ if (sc->scsi_done) sc->scsi_done(sc); - } /* fnic_fcpio_itmf_cmpl_handler @@ -974,8 +1015,21 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, fnic_release_ioreq_buf(fnic, io_req, sc); mempool_free(io_req, fnic->io_req_pool); - if (sc->scsi_done) + if (sc->scsi_done) { + FNIC_TRACE(fnic_fcpio_itmf_cmpl_handler, + sc->device->host->host_no, id, + sc, + jiffies_to_msecs(jiffies - start_time), + desc, + (((u64)hdr_status << 40) | + (u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | + (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]), + (((u64)CMD_FLAGS(sc) << 32) | + CMD_STATE(sc))); sc->scsi_done(sc); + } } } else if (id & FNIC_TAG_DEV_RST) { @@ -984,6 +1038,11 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, if (CMD_STATE(sc) == FNIC_IOREQ_ABTS_PENDING) { spin_unlock_irqrestore(io_lock, flags); CMD_FLAGS(sc) |= FNIC_DEV_RST_ABTS_PENDING; + FNIC_TRACE(fnic_fcpio_itmf_cmpl_handler, + sc->device->host->host_no, id, sc, + jiffies_to_msecs(jiffies - start_time), + desc, 0, + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Terminate pending " "dev reset cmpl recd. id %d status %s\n", @@ -994,6 +1053,11 @@ static void fnic_fcpio_itmf_cmpl_handler(struct fnic *fnic, if (CMD_FLAGS(sc) & FNIC_DEV_RST_TIMED_OUT) { /* Need to wait for terminate completion */ spin_unlock_irqrestore(io_lock, flags); + FNIC_TRACE(fnic_fcpio_itmf_cmpl_handler, + sc->device->host->host_no, id, sc, + jiffies_to_msecs(jiffies - start_time), + desc, 0, + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "dev reset cmpl recd after time out. " "id %d status %s\n", @@ -1142,8 +1206,18 @@ cleanup_scsi_cmd: " DID_TRANSPORT_DISRUPTED\n"); /* Complete the command to SCSI */ - if (sc->scsi_done) + if (sc->scsi_done) { + FNIC_TRACE(fnic_cleanup_io, + sc->device->host->host_no, i, sc, + jiffies_to_msecs(jiffies - start_time), + 0, ((u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | + (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]), + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); + sc->scsi_done(sc); + } } } @@ -1195,8 +1269,17 @@ wq_copy_cleanup_scsi_cmd: FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "wq_copy_cleanup_handler:" " DID_NO_CONNECT\n"); - if (sc->scsi_done) + if (sc->scsi_done) { + FNIC_TRACE(fnic_wq_copy_cleanup_handler, + sc->device->host->host_no, id, sc, + jiffies_to_msecs(jiffies - start_time), + 0, ((u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]), + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); + sc->scsi_done(sc); + } } static inline int fnic_queue_abort_io_req(struct fnic *fnic, int tag, @@ -1476,7 +1559,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) { struct fc_lport *lp; struct fnic *fnic; - struct fnic_io_req *io_req; + struct fnic_io_req *io_req = NULL; struct fc_rport *rport; spinlock_t *io_lock; unsigned long flags; @@ -1503,7 +1586,6 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) CMD_FLAGS(sc) = FNIC_NO_FLAGS; - if (lp->state != LPORT_ST_READY || !(lp->link_up)) { ret = FAILED; goto fnic_abort_cmd_end; @@ -1621,6 +1703,14 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) mempool_free(io_req, fnic->io_req_pool); fnic_abort_cmd_end: + FNIC_TRACE(fnic_abort_cmd, sc->device->host->host_no, + sc->request->tag, sc, + jiffies_to_msecs(jiffies - start_time), + 0, ((u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]), + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); + FNIC_SCSI_DBG(KERN_DEBUG, fnic->lport->host, "Returning from abort cmd type %x %s\n", task_req, (ret == SUCCESS) ? @@ -1891,7 +1981,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) { struct fc_lport *lp; struct fnic *fnic; - struct fnic_io_req *io_req; + struct fnic_io_req *io_req = NULL; struct fc_rport *rport; int status; int ret = FAILED; @@ -1899,7 +1989,7 @@ int fnic_device_reset(struct scsi_cmnd *sc) unsigned long flags; unsigned long start_time = 0; struct scsi_lun fc_lun; - int tag; + int tag = 0; DECLARE_COMPLETION_ONSTACK(tm_done); int tag_gen_flag = 0; /*to track tags allocated by fnic driver*/ @@ -2094,6 +2184,14 @@ fnic_device_reset_clean: } fnic_device_reset_end: + FNIC_TRACE(fnic_device_reset, sc->device->host->host_no, + sc->request->tag, sc, + jiffies_to_msecs(jiffies - start_time), + 0, ((u64)sc->cmnd[0] << 32 | + (u64)sc->cmnd[2] << 24 | (u64)sc->cmnd[3] << 16 | + (u64)sc->cmnd[4] << 8 | sc->cmnd[5]), + (((u64)CMD_FLAGS(sc) << 32) | CMD_STATE(sc))); + /* free tag if it is allocated */ if (unlikely(tag_gen_flag)) fnic_scsi_host_end_tag(fnic, sc); diff --git a/drivers/scsi/fnic/fnic_trace.c b/drivers/scsi/fnic/fnic_trace.c new file mode 100644 index 00000000000..23a60e3d852 --- /dev/null +++ b/drivers/scsi/fnic/fnic_trace.c @@ -0,0 +1,273 @@ +/* + * Copyright 2012 Cisco Systems, Inc. All rights reserved. + * + * This program is free software; you may redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; version 2 of the License. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, + * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF + * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND + * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS + * BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN + * ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN + * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE + * SOFTWARE. + */ + +#include +#include +#include +#include +#include +#include "fnic_io.h" +#include "fnic.h" + +unsigned int trace_max_pages; +static int fnic_max_trace_entries; + +static unsigned long fnic_trace_buf_p; +static DEFINE_SPINLOCK(fnic_trace_lock); + +static fnic_trace_dbg_t fnic_trace_entries; +int fnic_tracing_enabled = 1; + +/* + * fnic_trace_get_buf - Give buffer pointer to user to fill up trace information + * + * Description: + * This routine gets next available trace buffer entry location @wr_idx + * from allocated trace buffer pages and give that memory location + * to user to store the trace information. + * + * Return Value: + * This routine returns pointer to next available trace entry + * @fnic_buf_head for user to fill trace information. + */ +fnic_trace_data_t *fnic_trace_get_buf(void) +{ + unsigned long fnic_buf_head; + unsigned long flags; + + spin_lock_irqsave(&fnic_trace_lock, flags); + + /* + * Get next available memory location for writing trace information + * at @wr_idx and increment @wr_idx + */ + fnic_buf_head = + fnic_trace_entries.page_offset[fnic_trace_entries.wr_idx]; + fnic_trace_entries.wr_idx++; + + /* + * Verify if trace buffer is full then change wd_idx to + * start from zero + */ + if (fnic_trace_entries.wr_idx >= fnic_max_trace_entries) + fnic_trace_entries.wr_idx = 0; + + /* + * Verify if write index @wr_idx and read index @rd_idx are same then + * increment @rd_idx to move to next entry in trace buffer + */ + if (fnic_trace_entries.wr_idx == fnic_trace_entries.rd_idx) { + fnic_trace_entries.rd_idx++; + if (fnic_trace_entries.rd_idx >= fnic_max_trace_entries) + fnic_trace_entries.rd_idx = 0; + } + spin_unlock_irqrestore(&fnic_trace_lock, flags); + return (fnic_trace_data_t *)fnic_buf_head; +} + +/* + * fnic_get_trace_data - Copy trace buffer to a memory file + * @fnic_dbgfs_t: pointer to debugfs trace buffer + * + * Description: + * This routine gathers the fnic trace debugfs data from the fnic_trace_data_t + * buffer and dumps it to fnic_dbgfs_t. It will start at the rd_idx entry in + * the log and process the log until the end of the buffer. Then it will gather + * from the beginning of the log and process until the current entry @wr_idx. + * + * Return Value: + * This routine returns the amount of bytes that were dumped into fnic_dbgfs_t + */ +int fnic_get_trace_data(fnic_dbgfs_t *fnic_dbgfs_prt) +{ + int rd_idx; + int wr_idx; + int len = 0; + unsigned long flags; + char str[KSYM_SYMBOL_LEN]; + struct timespec val; + fnic_trace_data_t *tbp; + + spin_lock_irqsave(&fnic_trace_lock, flags); + rd_idx = fnic_trace_entries.rd_idx; + wr_idx = fnic_trace_entries.wr_idx; + if (wr_idx < rd_idx) { + while (1) { + /* Start from read index @rd_idx */ + tbp = (fnic_trace_data_t *) + fnic_trace_entries.page_offset[rd_idx]; + if (!tbp) { + spin_unlock_irqrestore(&fnic_trace_lock, flags); + return 0; + } + /* Convert function pointer to function name */ + if (sizeof(unsigned long) < 8) { + sprint_symbol(str, tbp->fnaddr.low); + jiffies_to_timespec(tbp->timestamp.low, &val); + } else { + sprint_symbol(str, tbp->fnaddr.val); + jiffies_to_timespec(tbp->timestamp.val, &val); + } + /* + * Dump trace buffer entry to memory file + * and increment read index @rd_idx + */ + len += snprintf(fnic_dbgfs_prt->buffer + len, + (trace_max_pages * PAGE_SIZE * 3) - len, + "%16lu.%16lu %-50s %8x %8x %16llx %16llx " + "%16llx %16llx %16llx\n", val.tv_sec, + val.tv_nsec, str, tbp->host_no, tbp->tag, + tbp->data[0], tbp->data[1], tbp->data[2], + tbp->data[3], tbp->data[4]); + rd_idx++; + /* + * If rd_idx is reached to maximum trace entries + * then move rd_idx to zero + */ + if (rd_idx > (fnic_max_trace_entries-1)) + rd_idx = 0; + /* + * Continure dumpping trace buffer entries into + * memory file till rd_idx reaches write index + */ + if (rd_idx == wr_idx) + break; + } + } else if (wr_idx > rd_idx) { + while (1) { + /* Start from read index @rd_idx */ + tbp = (fnic_trace_data_t *) + fnic_trace_entries.page_offset[rd_idx]; + if (!tbp) { + spin_unlock_irqrestore(&fnic_trace_lock, flags); + return 0; + } + /* Convert function pointer to function name */ + if (sizeof(unsigned long) < 8) { + sprint_symbol(str, tbp->fnaddr.low); + jiffies_to_timespec(tbp->timestamp.low, &val); + } else { + sprint_symbol(str, tbp->fnaddr.val); + jiffies_to_timespec(tbp->timestamp.val, &val); + } + /* + * Dump trace buffer entry to memory file + * and increment read index @rd_idx + */ + len += snprintf(fnic_dbgfs_prt->buffer + len, + (trace_max_pages * PAGE_SIZE * 3) - len, + "%16lu.%16lu %-50s %8x %8x %16llx %16llx " + "%16llx %16llx %16llx\n", val.tv_sec, + val.tv_nsec, str, tbp->host_no, tbp->tag, + tbp->data[0], tbp->data[1], tbp->data[2], + tbp->data[3], tbp->data[4]); + rd_idx++; + /* + * Continue dumpping trace buffer entries into + * memory file till rd_idx reaches write index + */ + if (rd_idx == wr_idx) + break; + } + } + spin_unlock_irqrestore(&fnic_trace_lock, flags); + return len; +} + +/* + * fnic_trace_buf_init - Initialize fnic trace buffer logging facility + * + * Description: + * Initialize trace buffer data structure by allocating required memory and + * setting page_offset information for every trace entry by adding trace entry + * length to previous page_offset value. + */ +int fnic_trace_buf_init(void) +{ + unsigned long fnic_buf_head; + int i; + int err = 0; + + trace_max_pages = fnic_trace_max_pages; + fnic_max_trace_entries = (trace_max_pages * PAGE_SIZE)/ + FNIC_ENTRY_SIZE_BYTES; + + fnic_trace_buf_p = (unsigned long)vmalloc((trace_max_pages * PAGE_SIZE)); + if (!fnic_trace_buf_p) { + printk(KERN_ERR PFX "Failed to allocate memory " + "for fnic_trace_buf_p\n"); + err = -ENOMEM; + goto err_fnic_trace_buf_init; + } + memset((void *)fnic_trace_buf_p, 0, (trace_max_pages * PAGE_SIZE)); + + fnic_trace_entries.page_offset = vmalloc(fnic_max_trace_entries * + sizeof(unsigned long)); + if (!fnic_trace_entries.page_offset) { + printk(KERN_ERR PFX "Failed to allocate memory for" + " page_offset\n"); + if (fnic_trace_buf_p) { + vfree((void *)fnic_trace_buf_p); + fnic_trace_buf_p = 0; + } + err = -ENOMEM; + goto err_fnic_trace_buf_init; + } + memset((void *)fnic_trace_entries.page_offset, 0, + (fnic_max_trace_entries * sizeof(unsigned long))); + fnic_trace_entries.wr_idx = fnic_trace_entries.rd_idx = 0; + fnic_buf_head = fnic_trace_buf_p; + + /* + * Set page_offset field of fnic_trace_entries struct by + * calculating memory location for every trace entry using + * length of each trace entry + */ + for (i = 0; i < fnic_max_trace_entries; i++) { + fnic_trace_entries.page_offset[i] = fnic_buf_head; + fnic_buf_head += FNIC_ENTRY_SIZE_BYTES; + } + err = fnic_trace_debugfs_init(); + if (err < 0) { + printk(KERN_ERR PFX "Failed to initialize debugfs for tracing\n"); + goto err_fnic_trace_debugfs_init; + } + printk(KERN_INFO PFX "Successfully Initialized Trace Buffer\n"); + return err; +err_fnic_trace_debugfs_init: + fnic_trace_free(); +err_fnic_trace_buf_init: + return err; +} + +/* + * fnic_trace_free - Free memory of fnic trace data structures. + */ +void fnic_trace_free(void) +{ + fnic_tracing_enabled = 0; + fnic_trace_debugfs_terminate(); + if (fnic_trace_entries.page_offset) { + vfree((void *)fnic_trace_entries.page_offset); + fnic_trace_entries.page_offset = NULL; + } + if (fnic_trace_buf_p) { + vfree((void *)fnic_trace_buf_p); + fnic_trace_buf_p = 0; + } + printk(KERN_INFO PFX "Successfully Freed Trace Buffer\n"); +} diff --git a/drivers/scsi/fnic/fnic_trace.h b/drivers/scsi/fnic/fnic_trace.h new file mode 100644 index 00000000000..cef42b4c4d6 --- /dev/null +++ b/drivers/scsi/fnic/fnic_trace.h @@ -0,0 +1,90 @@ +/* + * Copyright 2012 Cisco Systems, Inc. All rights reserved. + * + * This program is free software; you may redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; version 2 of the License. + * + * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, + * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF + * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND + * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS + * BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN + * ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN + * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE + * SOFTWARE. + */ + +#ifndef __FNIC_TRACE_H__ +#define __FNIC_TRACE_H__ + +#define FNIC_ENTRY_SIZE_BYTES 64 + +extern ssize_t simple_read_from_buffer(void __user *to, + size_t count, + loff_t *ppos, + const void *from, + size_t available); + +extern unsigned int fnic_trace_max_pages; +extern int fnic_tracing_enabled; +extern unsigned int trace_max_pages; + +typedef struct fnic_trace_dbg { + int wr_idx; + int rd_idx; + unsigned long *page_offset; +} fnic_trace_dbg_t; + +typedef struct fnic_dbgfs { + int buffer_len; + char *buffer; +} fnic_dbgfs_t; + +struct fnic_trace_data { + union { + struct { + u32 low; + u32 high; + }; + u64 val; + } timestamp, fnaddr; + u32 host_no; + u32 tag; + u64 data[5]; +} __attribute__((__packed__)); + +typedef struct fnic_trace_data fnic_trace_data_t; + +#define FNIC_TRACE_ENTRY_SIZE \ + (FNIC_ENTRY_SIZE_BYTES - sizeof(fnic_trace_data_t)) + +#define FNIC_TRACE(_fn, _hn, _t, _a, _b, _c, _d, _e) \ + if (unlikely(fnic_tracing_enabled)) { \ + fnic_trace_data_t *trace_buf = fnic_trace_get_buf(); \ + if (trace_buf) { \ + if (sizeof(unsigned long) < 8) { \ + trace_buf->timestamp.low = jiffies; \ + trace_buf->fnaddr.low = (u32)(unsigned long)_fn; \ + } else { \ + trace_buf->timestamp.val = jiffies; \ + trace_buf->fnaddr.val = (u64)(unsigned long)_fn; \ + } \ + trace_buf->host_no = _hn; \ + trace_buf->tag = _t; \ + trace_buf->data[0] = (u64)(unsigned long)_a; \ + trace_buf->data[1] = (u64)(unsigned long)_b; \ + trace_buf->data[2] = (u64)(unsigned long)_c; \ + trace_buf->data[3] = (u64)(unsigned long)_d; \ + trace_buf->data[4] = (u64)(unsigned long)_e; \ + } \ + } + +fnic_trace_data_t *fnic_trace_get_buf(void); +int fnic_get_trace_data(fnic_dbgfs_t *); +int fnic_trace_buf_init(void); +void fnic_trace_free(void); +int fnic_trace_debugfs_init(void); +void fnic_trace_debugfs_terminate(void); + +#endif -- cgit v1.2.3-70-g09d2