scsi: ftrace based scsi tracing feature
v3 cover scsi: ftrace based scsi tracing feature
Hi,
This is v3 patch series of SCSI trace. Since there has been no more new feedback on v2 for about a week, I've decided to post this.
Changelog from v2:
- fixed variable length command handling (removed the assumption that READ/WRITE(32) is only called if protection is enabled.)
Here are the links to the discussions on v2:
[PATCH 0/2 v2] scsi: ftrace based scsi tracing feature
http://marc.info/?l=linux-scsi&m=126500018231317&w=2 [PATCH 1/2 v2] scsi: add __print_hex() to ftrace http://marc.info/?l=linux-scsi&m=126500074718183&w=2 [PATCH 2/2 v2] scsi: add scsi trace core function and put trace points http://marc.info/?l=linux-scsi&m=126500087718320&w=2
This patchset applies to 2.6.33-rc8.
Thanks,
Kei
PATCH v3 1/2 scsi: add __print_hex() to ftrace
From: Li Zefan <[email protected]>
This is the same patch from v1.
__print_hex() prints values in an array in hex (w/o '0x') (space separated) EX) 92 33 32 f3 ee 4d
---
linux-2.6.33-rc8-trace-kei/include/linux/ftrace_event.h | 3 +++ linux-2.6.33-rc8-trace-kei/include/trace/ftrace.h | 3 +++ linux-2.6.33-rc8-trace-kei/kernel/trace/trace_output.c | 15 +++++++++++++++ 3 files changed, 21 insertions(+)
include/linux/ftrace_event.h renamed from include/linux/ftrace_event.h~ftrace_print_hex +3 -0
@@ -24,6 +24,9 @@ const char *ftrace_print_flags_seq(strucconst char *ftrace_print_symbols_seq (struct trace_seq *p,unsigned long val,const struct trace_print_flags *symbol_array); +const char *ftrace_print_hex_seq (struct trace_seq *p, +const unsigned char *buf,int len); +/* * The trace entry - the most basic unit of tracing. This is what * is printed in the end as a single line in the trace output, such as:
include/trace/ftrace.h renamed from include/trace/ftrace.h~ftrace_print_hex +3 -0
@@ -321,6 +321,9 @@ ftrace_format_##name(struct ftrace_eventftrace_print_symbols_seq (p, value, symbols); \ }) +#undef __print_hex +#define __print_hex (buf, buf_len) ftrace_print_hex_seq(p, buf, buf_len) +#undef DECLARE_EVENT_CLASS#define DECLARE_EVENT_CLASS (call, proto, args, tstruct, assign, print) \ static enum print_line_t \
kernel/trace/trace_output.c renamed from kernel/trace/trace_output.c~ftrace_print_hex +15 -0
@@ -355,6 +355,21 @@ ftrace_print_symbols_seq(struct trace_se }EXPORT_SYMBOL (ftrace_print_symbols_seq); +const char * +ftrace_print_hex_seq (struct trace_seq *p,const unsigned char *buf,int buf_len) +{ +int i; +const char *ret = p->buffer + p->len; + +for (i =0 ; i < buf_len; i++) +trace_seq_printf (p,"%s%2.2x" , i ==0 ?"" :" " , buf[i]); + +trace_seq_putc (p,0 ); + +return ret; +} +EXPORT_SYMBOL (ftrace_print_hex_seq); +#ifdef CONFIG_KRETPROBES static inline const char *kretprobed (const char *name) {
_
PATCH v3 2/2 scsi: add scsi trace core functions and put trace points
In reply to Kei TokunagaChangelog from v2:
- fixed variable length command handling (removed the assumption that READ/WRITE(32) is only called if protection is enabled.)
Trace points are the same from the last time as follows:
- when a command is about to be dispatched.
- when a command dispatched returns in error.
- when a command is done.
- when an error handler is about to waken up.
- when timeout of a command is detected.
Here is an outputs example:
# tracer: nop
#
# TASK-PID CPU# TIMESTAMP FUNCTION
# | | | | |
flush-8:0-3746 [001] 1374.517152: scsi_dispatch_cmd_start: host_no=0 channel=0 id=0 lun=0 cmnd=(WRITE_10 lba=32267539 txlen=8 raw=2a 00 01 ec 5d 13 00 00 08 00)
<idle>-0 [000] 1374.524964: scsi_dispatch_cmd_done: host_no=0 channel=0 id=0 lun=0 cmnd=(WRITE_10 lba=32267539 txlen=8 raw=2a 00 01 ec 5d 13 00 00 08 00) result=(driver=DRIVER_OK host=DID_OK message=COMMAND_COMPLETE status=SAM_STAT_GOOD)---
linux-2.6.33-rc8-trace-kei/drivers/scsi/Makefile | 1 linux-2.6.33-rc8-trace-kei/drivers/scsi/scsi.c | 6 linux-2.6.33-rc8-trace-kei/drivers/scsi/scsi_error.c | 4 linux-2.6.33-rc8-trace-kei/drivers/scsi/scsi_trace.c | 186 +++++++++ linux-2.6.33-rc8-trace-kei/include/trace/events/scsi.h | 328 +++++++++++++++++ linux-2.6.33-rc8-trace-kei/kernel/trace/trace_output.c | 1 6 files changed, 526 insertions(+)
drivers/scsi/Makefile renamed from drivers/scsi/Makefile~scsi_trace +1 -0
@@ -162,6 +162,7 @@ scsi_mod-y += scsi_scan.o scsi_sysfs.o scsi_mod-$(CONFIG_SCSI_NETLINK) += scsi_netlink.o scsi_mod-$(CONFIG_SYSCTL) += scsi_sysctl.o scsi_mod-$(CONFIG_SCSI_PROC_FS) += scsi_proc.o +scsi_mod-y += scsi_trace.o scsi_tgt-y += scsi_tgt_lib.o scsi_tgt_if.o
drivers/scsi/scsi.c renamed from drivers/scsi/scsi.c~scsi_trace +6 -0
@@ -67,6 +67,9 @@#include "scsi_priv.h" #include "scsi_logging.h" +#define CREATE_TRACE_POINTS +#include <trace/events/scsi.h> +static void scsi_done (struct scsi_cmnd *cmd);/*
@@ -747,10 +750,12 @@ int scsi_dispatch_cmd(struct scsi_cmnd * cmd->result = (DID_NO_CONNECT <<16 );scsi_done (cmd); }else { +trace_scsi_dispatch_cmd_start (cmd); rtn = host->hostt->queuecommand (cmd, scsi_done); }spin_unlock_irqrestore (host->host_lock, flags);if (rtn) { +trace_scsi_dispatch_cmd_error (cmd, rtn);if (rtn !=SCSI_MLQUEUE_DEVICE_BUSY && rtn !=SCSI_MLQUEUE_TARGET_BUSY ) rtn =SCSI_MLQUEUE_HOST_BUSY ;
@@ -781,6 +786,7 @@ int scsi_dispatch_cmd(struct scsi_cmnd **/ static void scsi_done (struct scsi_cmnd *cmd) { +trace_scsi_dispatch_cmd_done (cmd);blk_complete_request (cmd->request); }
drivers/scsi/scsi_error.c renamed from drivers/scsi/scsi_error.c~scsi_trace +4 -0
@@ -38,6 +38,8 @@#include "scsi_logging.h" #include "scsi_transport_api.h" +#include <trace/events/scsi.h> +#define SENSE_TIMEOUT (10*HZ)/*
@@ -51,6 +53,7 @@void scsi_eh_wakeup (struct Scsi_Host *shost) {if (shost->host_busy == shost->host_failed) { +trace_scsi_eh_wakeup (shost);wake_up_process (shost->ehandler);SCSI_LOG_ERROR_RECOVERY (5 ,printk ("Waking error handler thread\n" ));
@@ -126,6 +129,7 @@ enum blk_eh_timer_return scsi_times_out(struct scsi_cmnd *scmd = req->special;enum blk_eh_timer_return rtn =BLK_EH_NOT_HANDLED ; +trace_scsi_dispatch_cmd_timeout (scmd);scsi_log_completion (scmd,TIMEOUT_ERROR );if (scmd->device->host->transportt->eh_timed_out)
drivers/scsi/scsi_trace.c new file +186 -0
186 lines not on this page · raw message
include/trace/events/scsi.h new file +328 -0
328 lines not on this page · raw message
kernel/trace/trace_output.c renamed from kernel/trace/trace_output.c~scsi_trace +1 -0
@@ -209,6 +209,7 @@ int trace_seq_putc(struct trace_seq *s,return 1 ; } +EXPORT_SYMBOL (trace_seq_putc);int trace_seq_putmem (struct trace_seq *s,const void *mem,size_t len) {
_