xref: /openbmc/linux/drivers/scsi/fnic/fnic_trace.c (revision 12eb4683)
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 }
459