drivers/scsi/fnic/fnic_trace.c

   1 /*
   2  * Copyright 2012 Cisco Systems, Inc.  All rights reserved.
   3  *
   4  * This program is free software; you may redistribute it and/or modify
   5  * it under the terms of the GNU General Public License as published by
   6  * the Free Software Foundation; version 2 of the License.
   7  *
   8  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
   9  * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
  10  * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
  11  * NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS
  12  * BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN
  13  * ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN
  14  * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
  15  * SOFTWARE.
  16  */
  17
  18 #include <linux/module.h>
  19 #include <linux/mempool.h>
  20 #include <linux/errno.h>
  21 #include <linux/spinlock.h>
  22 #include <linux/kallsyms.h>
  23 #include "fnic_io.h"
  24 #include "fnic.h"
  25
  26 unsigned int trace_max_pages;
  27 static int fnic_max_trace_entries;
  28
  29 static unsigned long fnic_trace_buf_p;
  30 static DEFINE_SPINLOCK(fnic_trace_lock);
  31
  32 static fnic_trace_dbg_t fnic_trace_entries;
  33 int fnic_tracing_enabled = 1;
  34
  35 /*
  36  * fnic_trace_get_buf - Give buffer pointer to user to fill up trace information
  37  *
  38  * Description:
  39  * This routine gets next available trace buffer entry location @wr_idx
  40  * from allocated trace buffer pages and give that memory location
  41  * to user to store the trace information.
  42  *
  43  * Return Value:
  44  * This routine returns pointer to next available trace entry
  45  * @fnic_buf_head for user to fill trace information.
  46  */
  47 fnic_trace_data_t *fnic_trace_get_buf(void)
  48 {
  49         unsigned long fnic_buf_head;
  50         unsigned long flags;
  51
  52         spin_lock_irqsave(&fnic_trace_lock, flags);
  53
  54         /*
  55          * Get next available memory location for writing trace information
  56          * at @wr_idx and increment @wr_idx
  57          */
  58         fnic_buf_head =
  59                 fnic_trace_entries.page_offset[fnic_trace_entries.wr_idx];
  60         fnic_trace_entries.wr_idx++;
  61
  62         /*
  63          * Verify if trace buffer is full then change wd_idx to
  64          * start from zero
  65          */
  66         if (fnic_trace_entries.wr_idx >= fnic_max_trace_entries)
  67                 fnic_trace_entries.wr_idx = 0;
  68
  69         /*
  70          * Verify if write index @wr_idx and read index @rd_idx are same then
  71          * increment @rd_idx to move to next entry in trace buffer
  72          */
  73         if (fnic_trace_entries.wr_idx == fnic_trace_entries.rd_idx) {
  74                 fnic_trace_entries.rd_idx++;
  75                 if (fnic_trace_entries.rd_idx >= fnic_max_trace_entries)
  76                         fnic_trace_entries.rd_idx = 0;
  77         }
  78         spin_unlock_irqrestore(&fnic_trace_lock, flags);
  79         return (fnic_trace_data_t *)fnic_buf_head;
  80 }
  81
  82 /*
  83  * fnic_get_trace_data - Copy trace buffer to a memory file
  84  * @fnic_dbgfs_t: pointer to debugfs trace buffer
  85  *
  86  * Description:
  87  * This routine gathers the fnic trace debugfs data from the fnic_trace_data_t
  88  * buffer and dumps it to fnic_dbgfs_t. It will start at the rd_idx entry in
  89  * the log and process the log until the end of the buffer. Then it will gather
  90  * from the beginning of the log and process until the current entry @wr_idx.
  91  *
  92  * Return Value:
  93  * This routine returns the amount of bytes that were dumped into fnic_dbgfs_t
  94  */
  95 int fnic_get_trace_data(fnic_dbgfs_t *fnic_dbgfs_prt)
  96 {
  97         int rd_idx;
  98         int wr_idx;
  99         int len = 0;
 100         unsigned long flags;
 101         char str[KSYM_SYMBOL_LEN];
 102         struct timespec val;
 103         fnic_trace_data_t *tbp;
 104
 105         spin_lock_irqsave(&fnic_trace_lock, flags);
 106         rd_idx = fnic_trace_entries.rd_idx;
 107         wr_idx = fnic_trace_entries.wr_idx;
 108         if (wr_idx < rd_idx) {
 109                 while (1) {
 110                         /* Start from read index @rd_idx */
 111                         tbp = (fnic_trace_data_t *)
 112                                   fnic_trace_entries.page_offset[rd_idx];
 113                         if (!tbp) {
 114                                 spin_unlock_irqrestore(&fnic_trace_lock, flags);
 115                                 return 0;
 116                         }
 117                         /* Convert function pointer to function name */
 118                         if (sizeof(unsigned long) < 8) {
 119                                 sprint_symbol(str, tbp->fnaddr.low);
 120                                 jiffies_to_timespec(tbp->timestamp.low, &val);
 121                         } else {
 122                                 sprint_symbol(str, tbp->fnaddr.val);
 123                                 jiffies_to_timespec(tbp->timestamp.val, &val);
 124                         }
 125                         /*
 126                          * Dump trace buffer entry to memory file
 127                          * and increment read index @rd_idx
 128                          */
 129                         len += snprintf(fnic_dbgfs_prt->buffer + len,
 130                                   (trace_max_pages * PAGE_SIZE * 3) - len,
 131                                   "%16lu.%16lu %-50s %8x %8x %16llx %16llx "
 132                                   "%16llx %16llx %16llx\n", val.tv_sec,
 133                                   val.tv_nsec, str, tbp->host_no, tbp->tag,
 134                                   tbp->data[0], tbp->data[1], tbp->data[2],
 135                                   tbp->data[3], tbp->data[4]);
 136                         rd_idx++;
 137                         /*
 138                          * If rd_idx is reached to maximum trace entries
 139                          * then move rd_idx to zero
 140                          */
 141                         if (rd_idx > (fnic_max_trace_entries-1))
 142                                 rd_idx = 0;
 143                         /*
 144                          * Continure dumpping trace buffer entries into
 145                          * memory file till rd_idx reaches write index
 146                          */
 147                         if (rd_idx == wr_idx)
 148                                 break;
 149                 }
 150         } else if (wr_idx > rd_idx) {
 151                 while (1) {
 152                         /* Start from read index @rd_idx */
 153                         tbp = (fnic_trace_data_t *)
 154                                   fnic_trace_entries.page_offset[rd_idx];
 155                         if (!tbp) {
 156                                 spin_unlock_irqrestore(&fnic_trace_lock, flags);
 157                                 return 0;
 158                         }
 159                         /* Convert function pointer to function name */
 160                         if (sizeof(unsigned long) < 8) {
 161                                 sprint_symbol(str, tbp->fnaddr.low);
 162                                 jiffies_to_timespec(tbp->timestamp.low, &val);
 163                         } else {
 164                                 sprint_symbol(str, tbp->fnaddr.val);
 165                                 jiffies_to_timespec(tbp->timestamp.val, &val);
 166                         }
 167                         /*
 168                          * Dump trace buffer entry to memory file
 169                          * and increment read index @rd_idx
 170                          */
 171                         len += snprintf(fnic_dbgfs_prt->buffer + len,
 172                                   (trace_max_pages * PAGE_SIZE * 3) - len,
 173                                   "%16lu.%16lu %-50s %8x %8x %16llx %16llx "
 174                                   "%16llx %16llx %16llx\n", val.tv_sec,
 175                                   val.tv_nsec, str, tbp->host_no, tbp->tag,
 176                                   tbp->data[0], tbp->data[1], tbp->data[2],
 177                                   tbp->data[3], tbp->data[4]);
 178                         rd_idx++;
 179                         /*
 180                          * Continue dumpping trace buffer entries into
 181                          * memory file till rd_idx reaches write index
 182                          */
 183                         if (rd_idx == wr_idx)
 184                                 break;
 185                 }
 186         }
 187         spin_unlock_irqrestore(&fnic_trace_lock, flags);
 188         return len;
 189 }
 190
 191 /*
 192  * fnic_get_stats_data - Copy fnic stats buffer to a memory file
 193  * @fnic_dbgfs_t: pointer to debugfs fnic stats buffer
 194  *
 195  * Description:
 196  * This routine gathers the fnic stats debugfs data from the fnic_stats struct
 197  * and dumps it to stats_debug_info.
 198  *
 199  * Return Value:
 200  * This routine returns the amount of bytes that were dumped into
 201  * stats_debug_info
 202  */
 203 int fnic_get_stats_data(struct stats_debug_info *debug,
 204                         struct fnic_stats *stats)
 205 {
 206         int len = 0;
 207         int buf_size = debug->buf_size;
 208         struct timespec val1, val2;
 209
 210         len = snprintf(debug->debug_buffer + len, buf_size - len,
 211                   "------------------------------------------\n"
 212                   "\t\tIO Statistics\n"
 213                   "------------------------------------------\n");
 214         len += snprintf(debug->debug_buffer + len, buf_size - len,
 215                   "Number of Active IOs: %lld\nMaximum Active IOs: %lld\n"
 216                   "Number of IOs: %lld\nNumber of IO Completions: %lld\n"
 217                   "Number of IO Failures: %lld\nNumber of IO NOT Found: %lld\n"
 218                   "Number of Memory alloc Failures: %lld\n"
 219                   "Number of IOREQ Null: %lld\n"
 220                   "Number of SCSI cmd pointer Null: %lld\n",
 221                   (u64)atomic64_read(&stats->io_stats.active_ios),
 222                   (u64)atomic64_read(&stats->io_stats.max_active_ios),
 223                   (u64)atomic64_read(&stats->io_stats.num_ios),
 224                   (u64)atomic64_read(&stats->io_stats.io_completions),
 225                   (u64)atomic64_read(&stats->io_stats.io_failures),
 226                   (u64)atomic64_read(&stats->io_stats.io_not_found),
 227                   (u64)atomic64_read(&stats->io_stats.alloc_failures),
 228                   (u64)atomic64_read(&stats->io_stats.ioreq_null),
 229                   (u64)atomic64_read(&stats->io_stats.sc_null));
 230
 231         len += snprintf(debug->debug_buffer + len, buf_size - len,
 232                   "\n------------------------------------------\n"
 233                   "\t\tAbort Statistics\n"
 234                   "------------------------------------------\n");
 235         len += snprintf(debug->debug_buffer + len, buf_size - len,
 236                   "Number of Aborts: %lld\n"
 237                   "Number of Abort Failures: %lld\n"
 238                   "Number of Abort Driver Timeouts: %lld\n"
 239                   "Number of Abort FW Timeouts: %lld\n"
 240                   "Number of Abort IO NOT Found: %lld\n",
 241                   (u64)atomic64_read(&stats->abts_stats.aborts),
 242                   (u64)atomic64_read(&stats->abts_stats.abort_failures),
 243                   (u64)atomic64_read(&stats->abts_stats.abort_drv_timeouts),
 244                   (u64)atomic64_read(&stats->abts_stats.abort_fw_timeouts),
 245                   (u64)atomic64_read(&stats->abts_stats.abort_io_not_found));
 246
 247         len += snprintf(debug->debug_buffer + len, buf_size - len,
 248                   "\n------------------------------------------\n"
 249                   "\t\tTerminate Statistics\n"
 250                   "------------------------------------------\n");
 251         len += snprintf(debug->debug_buffer + len, buf_size - len,
 252                   "Number of Terminates: %lld\n"
 253                   "Maximum Terminates: %lld\n"
 254                   "Number of Terminate Driver Timeouts: %lld\n"
 255                   "Number of Terminate FW Timeouts: %lld\n"
 256                   "Number of Terminate IO NOT Found: %lld\n"
 257                   "Number of Terminate Failures: %lld\n",
 258                   (u64)atomic64_read(&stats->term_stats.terminates),
 259                   (u64)atomic64_read(&stats->term_stats.max_terminates),
 260                   (u64)atomic64_read(&stats->term_stats.terminate_drv_timeouts),
 261                   (u64)atomic64_read(&stats->term_stats.terminate_fw_timeouts),
 262                   (u64)atomic64_read(&stats->term_stats.terminate_io_not_found),
 263                   (u64)atomic64_read(&stats->term_stats.terminate_failures));
 264
 265         len += snprintf(debug->debug_buffer + len, buf_size - len,
 266                   "\n------------------------------------------\n"
 267                   "\t\tReset Statistics\n"
 268                   "------------------------------------------\n");
 269
 270         len += snprintf(debug->debug_buffer + len, buf_size - len,
 271                   "Number of Device Resets: %lld\n"
 272                   "Number of Device Reset Failures: %lld\n"
 273                   "Number of Device Reset Aborts: %lld\n"
 274                   "Number of Device Reset Timeouts: %lld\n"
 275                   "Number of Device Reset Terminates: %lld\n"
 276                   "Number of FW Resets: %lld\n"
 277                   "Number of FW Reset Completions: %lld\n"
 278                   "Number of FW Reset Failures: %lld\n"
 279                   "Number of Fnic Reset: %lld\n"
 280                   "Number of Fnic Reset Completions: %lld\n"
 281                   "Number of Fnic Reset Failures: %lld\n",
 282                   (u64)atomic64_read(&stats->reset_stats.device_resets),
 283                   (u64)atomic64_read(&stats->reset_stats.device_reset_failures),
 284                   (u64)atomic64_read(&stats->reset_stats.device_reset_aborts),
 285                   (u64)atomic64_read(&stats->reset_stats.device_reset_timeouts),
 286                   (u64)atomic64_read(
 287                           &stats->reset_stats.device_reset_terminates),
 288                   (u64)atomic64_read(&stats->reset_stats.fw_resets),
 289                   (u64)atomic64_read(&stats->reset_stats.fw_reset_completions),
 290                   (u64)atomic64_read(&stats->reset_stats.fw_reset_failures),
 291                   (u64)atomic64_read(&stats->reset_stats.fnic_resets),
 292                   (u64)atomic64_read(
 293                           &stats->reset_stats.fnic_reset_completions),
 294                   (u64)atomic64_read(&stats->reset_stats.fnic_reset_failures));
 295
 296         len += snprintf(debug->debug_buffer + len, buf_size - len,
 297                   "\n------------------------------------------\n"
 298                   "\t\tFirmware Statistics\n"
 299                   "------------------------------------------\n");
 300
 301         len += snprintf(debug->debug_buffer + len, buf_size - len,
 302                   "Number of Active FW Requests %lld\n"
 303                   "Maximum FW Requests: %lld\n"
 304                   "Number of FW out of resources: %lld\n"
 305                   "Number of FW IO errors: %lld\n",
 306                   (u64)atomic64_read(&stats->fw_stats.active_fw_reqs),
 307                   (u64)atomic64_read(&stats->fw_stats.max_fw_reqs),
 308                   (u64)atomic64_read(&stats->fw_stats.fw_out_of_resources),
 309                   (u64)atomic64_read(&stats->fw_stats.io_fw_errs));
 310
 311         len += snprintf(debug->debug_buffer + len, buf_size - len,
 312                   "\n------------------------------------------\n"
 313                   "\t\tVlan Discovery Statistics\n"
 314                   "------------------------------------------\n");
 315
 316         len += snprintf(debug->debug_buffer + len, buf_size - len,
 317                   "Number of Vlan Discovery Requests Sent %lld\n"
 318                   "Vlan Response Received with no FCF VLAN ID: %lld\n"
 319                   "No solicitations recvd after vlan set, expiry count: %lld\n"
 320                   "Flogi rejects count: %lld\n",
 321                   (u64)atomic64_read(&stats->vlan_stats.vlan_disc_reqs),
 322                   (u64)atomic64_read(&stats->vlan_stats.resp_withno_vlanID),
 323                   (u64)atomic64_read(&stats->vlan_stats.sol_expiry_count),
 324                   (u64)atomic64_read(&stats->vlan_stats.flogi_rejects));
 325
 326         len += snprintf(debug->debug_buffer + len, buf_size - len,
 327                   "\n------------------------------------------\n"
 328                   "\t\tOther Important Statistics\n"
 329                   "------------------------------------------\n");
 330
 331         jiffies_to_timespec(stats->misc_stats.last_isr_time, &val1);
 332         jiffies_to_timespec(stats->misc_stats.last_ack_time, &val2);
 333
 334         len += snprintf(debug->debug_buffer + len, buf_size - len,
 335                   "Last ISR time: %llu (%8lu.%8lu)\n"
 336                   "Last ACK time: %llu (%8lu.%8lu)\n"
 337                   "Number of ISRs: %lld\n"
 338                   "Maximum CQ Entries: %lld\n"
 339                   "Number of ACK index out of range: %lld\n"
 340                   "Number of data count mismatch: %lld\n"
 341                   "Number of FCPIO Timeouts: %lld\n"
 342                   "Number of FCPIO Aborted: %lld\n"
 343                   "Number of SGL Invalid: %lld\n"
 344                   "Number of Copy WQ Alloc Failures for ABTs: %lld\n"
 345                   "Number of Copy WQ Alloc Failures for Device Reset: %lld\n"
 346                   "Number of Copy WQ Alloc Failures for IOs: %lld\n"
 347                   "Number of no icmnd itmf Completions: %lld\n"
 348                   "Number of QUEUE Fulls: %lld\n"
 349                   "Number of rport not ready: %lld\n"
 350                   "Number of receive frame errors: %lld\n",
 351                   (u64)stats->misc_stats.last_isr_time,
 352                   val1.tv_sec, val1.tv_nsec,
 353                   (u64)stats->misc_stats.last_ack_time,
 354                   val2.tv_sec, val2.tv_nsec,
 355                   (u64)atomic64_read(&stats->misc_stats.isr_count),
 356                   (u64)atomic64_read(&stats->misc_stats.max_cq_entries),
 357                   (u64)atomic64_read(&stats->misc_stats.ack_index_out_of_range),
 358                   (u64)atomic64_read(&stats->misc_stats.data_count_mismatch),
 359                   (u64)atomic64_read(&stats->misc_stats.fcpio_timeout),
 360                   (u64)atomic64_read(&stats->misc_stats.fcpio_aborted),
 361                   (u64)atomic64_read(&stats->misc_stats.sgl_invalid),
 362                   (u64)atomic64_read(
 363                           &stats->misc_stats.abts_cpwq_alloc_failures),
 364                   (u64)atomic64_read(
 365                           &stats->misc_stats.devrst_cpwq_alloc_failures),
 366                   (u64)atomic64_read(&stats->misc_stats.io_cpwq_alloc_failures),
 367                   (u64)atomic64_read(&stats->misc_stats.no_icmnd_itmf_cmpls),
 368                   (u64)atomic64_read(&stats->misc_stats.queue_fulls),
 369                   (u64)atomic64_read(&stats->misc_stats.rport_not_ready),
 370                   (u64)atomic64_read(&stats->misc_stats.frame_errors));
 371
 372         return len;
 373
 374 }
 375
 376 /*
 377  * fnic_trace_buf_init - Initialize fnic trace buffer logging facility
 378  *
 379  * Description:
 380  * Initialize trace buffer data structure by allocating required memory and
 381  * setting page_offset information for every trace entry by adding trace entry
 382  * length to previous page_offset value.
 383  */
 384 int fnic_trace_buf_init(void)
 385 {
 386         unsigned long fnic_buf_head;
 387         int i;
 388         int err = 0;
 389
 390         trace_max_pages = fnic_trace_max_pages;
 391         fnic_max_trace_entries = (trace_max_pages * PAGE_SIZE)/
 392                                           FNIC_ENTRY_SIZE_BYTES;
 393
 394         fnic_trace_buf_p = (unsigned long)vmalloc((trace_max_pages * PAGE_SIZE));
 395         if (!fnic_trace_buf_p) {
 396                 printk(KERN_ERR PFX "Failed to allocate memory "
 397                                   "for fnic_trace_buf_p\n");
 398                 err = -ENOMEM;
 399                 goto err_fnic_trace_buf_init;
 400         }
 401         memset((void *)fnic_trace_buf_p, 0, (trace_max_pages * PAGE_SIZE));
 402
 403         fnic_trace_entries.page_offset = vmalloc(fnic_max_trace_entries *
 404                                                   sizeof(unsigned long));
 405         if (!fnic_trace_entries.page_offset) {
 406                 printk(KERN_ERR PFX "Failed to allocate memory for"
 407                                   " page_offset\n");
 408                 if (fnic_trace_buf_p) {
 409                         vfree((void *)fnic_trace_buf_p);
 410                         fnic_trace_buf_p = 0;
 411                 }
 412                 err = -ENOMEM;
 413                 goto err_fnic_trace_buf_init;
 414         }
 415         memset((void *)fnic_trace_entries.page_offset, 0,
 416                   (fnic_max_trace_entries * sizeof(unsigned long)));
 417         fnic_trace_entries.wr_idx = fnic_trace_entries.rd_idx = 0;
 418         fnic_buf_head = fnic_trace_buf_p;
 419
 420         /*
 421          * Set page_offset field of fnic_trace_entries struct by
 422          * calculating memory location for every trace entry using
 423          * length of each trace entry
 424          */
 425         for (i = 0; i < fnic_max_trace_entries; i++) {
 426                 fnic_trace_entries.page_offset[i] = fnic_buf_head;
 427                 fnic_buf_head += FNIC_ENTRY_SIZE_BYTES;
 428         }
 429         err = fnic_trace_debugfs_init();
 430         if (err < 0) {
 431                 printk(KERN_ERR PFX "Failed to initialize debugfs for tracing\n");
 432                 goto err_fnic_trace_debugfs_init;
 433         }
 434         printk(KERN_INFO PFX "Successfully Initialized Trace Buffer\n");
 435         return err;
 436 err_fnic_trace_debugfs_init:
 437         fnic_trace_free();
 438 err_fnic_trace_buf_init:
 439         return err;
 440 }
 441
 442 /*
 443  * fnic_trace_free - Free memory of fnic trace data structures.
 444  */
 445 void fnic_trace_free(void)
 446 {
 447         fnic_tracing_enabled = 0;
 448         fnic_trace_debugfs_terminate();
 449         if (fnic_trace_entries.page_offset) {
 450                 vfree((void *)fnic_trace_entries.page_offset);
 451                 fnic_trace_entries.page_offset = NULL;
 452         }
 453         if (fnic_trace_buf_p) {
 454                 vfree((void *)fnic_trace_buf_p);
 455                 fnic_trace_buf_p = 0;
 456         }
 457         printk(KERN_INFO PFX "Successfully Freed Trace Buffer\n");
 458 }