From 445d2960862eb3c972012bbbb9cf4ee338334b0a Mon Sep 17 00:00:00 2001 From: Satish Kharat Date: Tue, 28 Feb 2017 16:15:59 -0800 Subject: scsi: fnic: Adding debug IO and Abort latency counter to fnic stats The IO and Abort latency counter counts the time taken to complete the IO and abort command into broad buckets. This is not intended for performance measurement, just a debug statistic. current_max_io_time tries to keep track of the maximum time an IO has taken to complete if it is > 30sec. Signed-off-by: Satish Kharat Signed-off-by: Sesidhar Baddela Signed-off-by: Martin K. Petersen --- drivers/scsi/fnic/fnic_scsi.c | 43 +++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 43 insertions(+) (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 190c0663aaf4..d048f3b5006f 100644 --- a/drivers/scsi/fnic/fnic_scsi.c +++ b/drivers/scsi/fnic/fnic_scsi.c @@ -823,6 +823,7 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, spinlock_t *io_lock; u64 cmd_trace; unsigned long start_time; + unsigned long io_duration_time; /* Decode the cmpl description to get the io_req id */ fcpio_header_dec(&desc->hdr, &type, &hdr_status, &tag); @@ -1016,6 +1017,28 @@ static void fnic_fcpio_icmnd_cmpl_handler(struct fnic *fnic, else atomic64_inc(&fnic_stats->io_stats.io_completions); + + io_duration_time = jiffies_to_msecs(jiffies) - jiffies_to_msecs(io_req->start_time); + + if(io_duration_time <= 10) + atomic64_inc(&fnic_stats->io_stats.io_btw_0_to_10_msec); + else if(io_duration_time <= 100) + atomic64_inc(&fnic_stats->io_stats.io_btw_10_to_100_msec); + else if(io_duration_time <= 500) + atomic64_inc(&fnic_stats->io_stats.io_btw_100_to_500_msec); + else if(io_duration_time <= 5000) + atomic64_inc(&fnic_stats->io_stats.io_btw_500_to_5000_msec); + else if(io_duration_time <= 10000) + atomic64_inc(&fnic_stats->io_stats.io_btw_5000_to_10000_msec); + else if(io_duration_time <= 30000) + atomic64_inc(&fnic_stats->io_stats.io_btw_10000_to_30000_msec); + else { + atomic64_inc(&fnic_stats->io_stats.io_greater_than_30000_msec); + + if(io_duration_time > atomic64_read(&fnic_stats->io_stats.current_max_io_time)) + atomic64_set(&fnic_stats->io_stats.current_max_io_time, io_duration_time); + } + /* Call SCSI completion function to complete the IO */ if (sc->scsi_done) sc->scsi_done(sc); @@ -1790,6 +1813,7 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) struct terminate_stats *term_stats; enum fnic_ioreq_state old_ioreq_state; int tag; + unsigned long abt_issued_time; DECLARE_COMPLETION_ONSTACK(tm_done); /* Wait for rport to unblock */ @@ -1843,6 +1867,25 @@ int fnic_abort_cmd(struct scsi_cmnd *sc) spin_unlock_irqrestore(io_lock, flags); goto wait_pending; } + + abt_issued_time = jiffies_to_msecs(jiffies) - jiffies_to_msecs(io_req->start_time); + if (abt_issued_time <= 6000) + atomic64_inc(&abts_stats->abort_issued_btw_0_to_6_sec); + else if (abt_issued_time > 6000 && abt_issued_time <= 20000) + atomic64_inc(&abts_stats->abort_issued_btw_6_to_20_sec); + else if (abt_issued_time > 20000 && abt_issued_time <= 30000) + atomic64_inc(&abts_stats->abort_issued_btw_20_to_30_sec); + else if (abt_issued_time > 30000 && abt_issued_time <= 40000) + atomic64_inc(&abts_stats->abort_issued_btw_30_to_40_sec); + else if (abt_issued_time > 40000 && abt_issued_time <= 50000) + atomic64_inc(&abts_stats->abort_issued_btw_40_to_50_sec); + else if (abt_issued_time > 50000 && abt_issued_time <= 60000) + atomic64_inc(&abts_stats->abort_issued_btw_50_to_60_sec); + else + atomic64_inc(&abts_stats->abort_issued_greater_than_60_sec); + + FNIC_SCSI_DBG(KERN_INFO, fnic->lport->host, + "CBD Opcode: %02x Abort issued time: %lu msec\n", sc->cmnd[0], abt_issued_time); /* * Command is still pending, need to abort it * If the firmware completes the command after this point, -- cgit v1.2.3