vfio-ccw: A couple trace changes
Subsystems (4)
Eric Farman
maintainerv2 cover vfio-ccw: A couple trace changes
Here a couple updates to the vfio-ccw traces in the kernel, based on things I've been using locally. Perhaps they'll be useful for future debugging.
Steffen's comments earlier today (thank you!) were simple enough that here's a quick turnaround on a v2:
v1/RFC -> v2:
- Convert state/event=%x to %d
- Use individual fields for cssid/ssid/sch_no, to enable filtering by device
- Add 0x prefix to remaining %x substitution in existing trace
Eric Farman (4):
vfio-ccw: Refactor how the traces are built
vfio-ccw: Trace the FSM jumptable
vfio-ccw: Add a trace for asynchronous requests
vfio-ccw: Rework the io_fctl trace
drivers/s390/cio/Makefile | 4 +- drivers/s390/cio/vfio_ccw_cp.h | 1 + drivers/s390/cio/vfio_ccw_fsm.c | 11 +++-- drivers/s390/cio/vfio_ccw_private.h | 1 + drivers/s390/cio/vfio_ccw_trace.c | 14 ++++++ drivers/s390/cio/vfio_ccw_trace.h | 76 ++++++++++++++++++++++++++--- 6 files changed, 93 insertions(+), 14 deletions(-) create mode 100644 drivers/s390/cio/vfio_ccw_trace.c
Signature · 1 line
2.17.1
Eric Farman
maintainerPATCH v2 1/4 vfio-ccw: Refactor how the traces are built
Commit 3cd90214b70f ("vfio: ccw: add tracepoints for interesting error paths") added a quick trace point to determine where a channel program failed while being processed. It's a great addition, but adding more traces to vfio-ccw is more cumbersome than it needs to be.
Let's refactor how this is done, so that additional traces are easier to add and can exist outside of the FSM if we ever desire.
--- drivers/s390/cio/Makefile | 4 ++-- drivers/s390/cio/vfio_ccw_cp.h | 1 + drivers/s390/cio/vfio_ccw_fsm.c | 3 --- drivers/s390/cio/vfio_ccw_trace.c | 12 ++++++++++++ drivers/s390/cio/vfio_ccw_trace.h | 2 ++ 5 files changed, 17 insertions(+), 5 deletions(-) create mode 100644 drivers/s390/cio/vfio_ccw_trace.c
drivers/s390/cio/Makefile +2 -2
@@ -5,7 +5,7 @@ # The following is required for define_trace.h to find ./trace.h CFLAGS_trace.o := -I$(src) -CFLAGS_vfio_ccw_fsm.o := -I$(src) +CFLAGS_vfio_ccw_trace.o := -I$(src) obj-y += airq.o blacklist.o chsc.o cio.o css.o chp.o idset.o isc.o \ fcx.o itcw.o crw.o ccwreq.o trace.o ioasm.o
@@ -21,5 +21,5 @@ qdio-objs := qdio_main.o qdio_thinint.o qdio_debug.o qdio_setup.o obj-$(CONFIG_QDIO) += qdio.o vfio_ccw-objs += vfio_ccw_drv.o vfio_ccw_cp.o vfio_ccw_ops.o vfio_ccw_fsm.o \ - vfio_ccw_async.o + vfio_ccw_async.o vfio_ccw_trace.o obj-$(CONFIG_VFIO_CCW) += vfio_ccw.o
drivers/s390/cio/vfio_ccw_cp.h +1 -0
@@ -15,6 +15,7 @@#include <asm/scsw.h> #include "orb.h" +#include "vfio_ccw_trace.h" /* * Max length for ccw chain.
drivers/s390/cio/vfio_ccw_fsm.c +0 -3
@@ -15,9 +15,6 @@#include "ioasm.h" #include "vfio_ccw_private.h" -#define CREATE_TRACE_POINTS -#include "vfio_ccw_trace.h" -static int fsm_io_helper (struct vfio_ccw_private *private) {struct subchannel *sch;
drivers/s390/cio/vfio_ccw_trace.c new file +12 -0
@@ -0,0 +1,12 @@ +// SPDX-License-Identifier: GPL-2.0 +/* +* Tracepoint definitions for vfio_ccw +* +* Copyright IBM Corp. 2019 +* Author(s): Eric Farman <[email protected]> +*/ + +#define CREATE_TRACE_POINTS +#include "vfio_ccw_trace.h" + +EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_io_fctl);
drivers/s390/cio/vfio_ccw_trace.h +2 -0
@@ -7,6 +7,8 @@* Halil Pasic <[email protected]> */ +#include "cio.h" +#undef TRACE_SYSTEM#define TRACE_SYSTEM vfio_ccw
Signature · 1 line
2.17.1
Re: [PATCH v2 1/4] vfio-ccw: Refactor how the traces are built
Quoted 9 lines · On Wed, 16 Oct 2019 03:58:19 +0200 Eric Farman <[email protected]> wrote:
Commit
3cd90214b70f("vfio: ccw: add tracepoints for interesting error paths") added a quick trace point to determine where a channel program failed while being processed. It's a great addition, but adding more traces to vfio-ccw is more cumbersome than it needs to be.Let's refactor how this is done, so that additional traces are easier to add and can exist outside of the FSM if we ever desire.
Signed-off-by Eric Farman <[email protected]>
Quoted 8 lines
--- drivers/s390/cio/Makefile | 4 ++-- drivers/s390/cio/vfio_ccw_cp.h | 1 + drivers/s390/cio/vfio_ccw_fsm.c | 3 --- drivers/s390/cio/vfio_ccw_trace.c | 12 ++++++++++++ drivers/s390/cio/vfio_ccw_trace.h | 2 ++ 5 files changed, 17 insertions(+), 5 deletions(-) create mode 100644 drivers/s390/cio/vfio_ccw_trace.c
Eric Farman
maintainerPATCH v2 2/4 vfio-ccw: Trace the FSM jumptable
In reply to Eric FarmanIt would be nice if we could track the sequence of events within vfio-ccw, based on the state of the device/FSM and our calling sequence within it. So let's add a simple trace here so we can watch the states change as things go, and allow it to be folded into the rest of the other cio traces.
--- drivers/s390/cio/vfio_ccw_private.h | 1 + drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 26 ++++++++++++++++++++++++++ 3 files changed, 28 insertions(+)
drivers/s390/cio/vfio_ccw_private.h +1 -0
@@ -135,6 +135,7 @@ extern fsm_func_t *vfio_ccw_jumptable[NR_VFIO_CCW_STATES][NR_VFIO_CCW_EVENTS];static inline void vfio_ccw_fsm_event (struct vfio_ccw_private *private,int event) { +trace_vfio_ccw_fsm_event (private->sch->schid, private->state, event); vfio_ccw_jumptable[private->state][event](private, event); }
drivers/s390/cio/vfio_ccw_trace.c +1 -0
@@ -9,4 +9,5 @@#define CREATE_TRACE_POINTS #include "vfio_ccw_trace.h" +EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_event);EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_io_fctl);
drivers/s390/cio/vfio_ccw_trace.h +26 -0
@@ -17,6 +17,32 @@#include <linux/tracepoint.h> +TRACE_EVENT (vfio_ccw_fsm_event, + TP_PROTO(struct subchannel_id schid, int state, int event), +TP_ARGS (schid, state, event), + +TP_STRUCT__entry ( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, schno) + __field(int, state) +__field (int, event) + ), + +TP_fast_assign ( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid; + __entry->schno = schid.sch_no; + __entry->state = state; + __entry->event = event; + ), + +TP_printk ("schid=%x.%x.%04x state=%d event=%d" , + __entry->cssid, __entry->ssid, __entry->schno, + __entry->state, + __entry->event) +); + TRACE_EVENT(vfio_ccw_io_fctl, TP_PROTO(int fctl, struct subchannel_id schid, int errno, char *errstr), TP_ARGS(fctl, schid, errno, errstr),
Signature · 1 line
2.17.1
Re: [PATCH v2 2/4] vfio-ccw: Trace the FSM jumptable
Quoted 6 lines · On Wed, 16 Oct 2019 03:58:20 +0200 Eric Farman <[email protected]> wrote:
It would be nice if we could track the sequence of events within vfio-ccw, based on the state of the device/FSM and our calling sequence within it. So let's add a simple trace here so we can watch the states change as things go, and allow it to be folded into the rest of the other cio traces.
Quoted 6 lines
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_private.h | 1 + drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 26 ++++++++++++++++++++++++++ 3 files changed, 28 insertions(+)
Eric Farman
maintainerPATCH v2 3/4 vfio-ccw: Add a trace for asynchronous requests
In reply to Eric FarmanSince the asynchronous requests are typically associated with error recovery, let's add a simple trace when one of those is issued to a device.
--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++++ drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 30 ++++++++++++++++++++++++++++++ 3 files changed, 35 insertions(+)
drivers/s390/cio/vfio_ccw_fsm.c +4 -0
@@ -341,6 +341,10 @@ static void fsm_async_request(struct vfio_ccw_private *private,/* should not happen? */ cmd_region->ret_code = -EINVAL ; } + +trace_vfio_ccw_fsm_async_request (get_schid (private), + cmd_region->command, + cmd_region->ret_code); }/*
drivers/s390/cio/vfio_ccw_trace.c +1 -0
@@ -9,5 +9,6 @@#define CREATE_TRACE_POINTS #include "vfio_ccw_trace.h" +EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_async_request);EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_event);EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_io_fctl);
drivers/s390/cio/vfio_ccw_trace.h +30 -0
@@ -17,6 +17,36 @@#include <linux/tracepoint.h> +TRACE_EVENT (vfio_ccw_fsm_async_request, + TP_PROTO(struct subchannel_id schid, + int command, + int errno), +TP_ARGS (schid, command, errno), + +TP_STRUCT__entry ( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) + __field(int, command) +__field (int, errno) + ), + +TP_fast_assign ( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid; + __entry->sch_no = schid.sch_no; + __entry->command = command; + __entry->errno = errno; + ), + +TP_printk ("schid=%x.%x.%04x command=%d errno=%d" , + __entry->cssid, + __entry->ssid, + __entry->sch_no, + __entry->command, + __entry->errno) +); + TRACE_EVENT(vfio_ccw_fsm_event, TP_PROTO(struct subchannel_id schid, int state, int event), TP_ARGS(schid, state, event),
Signature · 1 line
2.17.1
Re: [PATCH v2 3/4] vfio-ccw: Add a trace for asynchronous requests
Quoted 10 lines · On Wed, 16 Oct 2019 03:58:21 +0200 Eric Farman <[email protected]> wrote:
Since the asynchronous requests are typically associated with error recovery, let's add a simple trace when one of those is issued to a device.
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++++ drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 30 ++++++++++++++++++++++++++++++ 3 files changed, 35 insertions(+)
(...)
Quoted 21 lines
drivers/s390/cio/vfio_ccw_trace.h +13
-0@@ -17,6 +17,36 @@#include <linux/tracepoint.h> +TRACE_EVENT(vfio_ccw_fsm_async_request, + TP_PROTO(struct subchannel_id schid, + int command, + int errno), + TP_ARGS(schid, command, errno), + + TP_STRUCT__entry( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) + __field(int, command) + __field(int, errno) + ),
drivers/s390/cio/vfio_ccw_trace.h line 42
Quoted 10 lines
drivers/s390/cio/vfio_ccw_trace.h +10
-0+ +TP_fast_assign ( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid; + __entry->sch_no = schid.sch_no; + __entry->command = command; + __entry->errno = errno; + ), + + TP_printk("schid=%x.%x.%04x command=%d errno=%d",
I'd probably rather print the command as a hex value.
Quoted 10 lines
drivers/s390/cio/vfio_ccw_trace.h +7
-0+ __entry->cssid, + __entry->ssid, + __entry->sch_no, + __entry->command, + __entry->errno) +); + TRACE_EVENT(vfio_ccw_fsm_event, TP_PROTO(struct subchannel_id schid, int state, int event), TP_ARGS(schid, state, event),
Eric Farman
maintainerRe: [PATCH v2 3/4] vfio-ccw: Add a trace for asynchronous requests
Quoted 41 lines · Cornelia Huck
Quoted 10 lines · On Wed, 16 Oct 2019 03:58:21 +0200 Eric Farman <[email protected]> wrote:
Since the asynchronous requests are typically associated with error recovery, let's add a simple trace when one of those is issued to a device.
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++++ drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 30 ++++++++++++++++++++++++++++++ 3 files changed, 35 insertions(+)(...)
Quoted 25 lines
drivers/s390/cio/vfio_ccw_trace.h +17
-0@@ -17,6 +17,36 @@#include <linux/tracepoint.h> +TRACE_EVENT(vfio_ccw_fsm_async_request, + TP_PROTO(struct subchannel_id schid, + int command, + int errno), + TP_ARGS(schid, command, errno), + + TP_STRUCT__entry( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) + __field(int, command) + __field(int, errno) + ), + + TP_fast_assign( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid;
Quoted 8 lines
drivers/s390/cio/vfio_ccw_trace.h line 42
Quoted 6 lines
drivers/s390/cio/vfio_ccw_trace.h +6
-0+ __entry->sch_no = schid.sch_no; + __entry->command = command; + __entry->errno = errno; + ), + + TP_printk("schid=%x.%x.%04x command=%d errno=%d",I'd probably rather print the command as a hex value.
I'm fine with that too. Want me to send an update?
Quoted 12 lines
Quoted 11 lines
drivers/s390/cio/vfio_ccw_trace.h +7
-0+ __entry->cssid, + __entry->ssid, + __entry->sch_no, + __entry->command, + __entry->errno) +); + TRACE_EVENT(vfio_ccw_fsm_event, TP_PROTO(struct subchannel_id schid, int state, int event), TP_ARGS(schid, state, event),
Re: [PATCH v2 3/4] vfio-ccw: Add a trace for asynchronous requests
Quoted 51 lines · On Wed, 16 Oct 2019 07:36:09 -0400 Eric Farman <[email protected]> wrote:
Quoted 41 lines · Cornelia Huck
Quoted 10 lines · On Wed, 16 Oct 2019 03:58:21 +0200 Eric Farman <[email protected]> wrote:
Since the asynchronous requests are typically associated with error recovery, let's add a simple trace when one of those is issued to a device.
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++++ drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 30 ++++++++++++++++++++++++++++++ 3 files changed, 35 insertions(+)(...)
Quoted 25 lines
drivers/s390/cio/vfio_ccw_trace.h +17
-0@@ -17,6 +17,36 @@#include <linux/tracepoint.h> +TRACE_EVENT(vfio_ccw_fsm_async_request, + TP_PROTO(struct subchannel_id schid, + int command, + int errno), + TP_ARGS(schid, command, errno), + + TP_STRUCT__entry( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) + __field(int, command) + __field(int, errno) + ), + + TP_fast_assign( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid;Quoted 8 lines
drivers/s390/cio/vfio_ccw_trace.h line 42
Quoted 6 lines
drivers/s390/cio/vfio_ccw_trace.h +6
-0+ __entry->sch_no = schid.sch_no; + __entry->command = command; + __entry->errno = errno; + ), + + TP_printk("schid=%x.%x.%04x command=%d errno=%d",I'd probably rather print the command as a hex value.
Quoted 1 line
I'm fine with that too. Want me to send an update?
I think that would be the easiest way.
Quoted 13 lines
Quoted 13 lines
Quoted 12 lines
drivers/s390/cio/vfio_ccw_trace.h +7
-0+ __entry->cssid, + __entry->ssid, + __entry->sch_no, + __entry->command, + __entry->errno) +); + TRACE_EVENT(vfio_ccw_fsm_event, TP_PROTO(struct subchannel_id schid, int state, int event), TP_ARGS(schid, state, event),
Eric Farman
maintainerRe: [PATCH v2 3/4] vfio-ccw: Add a trace for asynchronous requests
Quoted 54 lines · Cornelia Huck
Quoted 51 lines · On Wed, 16 Oct 2019 07:36:09 -0400 Eric Farman <[email protected]> wrote:
Quoted 49 lines · Cornelia Huck
Quoted 10 lines · On Wed, 16 Oct 2019 03:58:21 +0200 Eric Farman <[email protected]> wrote:
Since the asynchronous requests are typically associated with error recovery, let's add a simple trace when one of those is issued to a device.
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++++ drivers/s390/cio/vfio_ccw_trace.c | 1 + drivers/s390/cio/vfio_ccw_trace.h | 30 ++++++++++++++++++++++++++++++ 3 files changed, 35 insertions(+)(...)
Quoted 21 lines
drivers/s390/cio/vfio_ccw_trace.h +13
-0@@ -17,6 +17,36 @@#include <linux/tracepoint.h> +TRACE_EVENT(vfio_ccw_fsm_async_request, + TP_PROTO(struct subchannel_id schid, + int command, + int errno), + TP_ARGS(schid, command, errno), + + TP_STRUCT__entry( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) + __field(int, command) + __field(int, errno) + ),drivers/s390/cio/vfio_ccw_trace.h line 42
Quoted 10 lines
drivers/s390/cio/vfio_ccw_trace.h +10
-0+ +TP_fast_assign ( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid; + __entry->sch_no = schid.sch_no; + __entry->command = command; + __entry->errno = errno; + ), + + TP_printk("schid=%x.%x.%04x command=%d errno=%d",I'd probably rather print the command as a hex value.
Quoted 3 lines
Quoted 1 line
I'm fine with that too. Want me to send an update?
I think that would be the easiest way.
Will do. Thanks for the reviews on the other ones!
- Eric
Quoted 15 lines
Quoted 14 lines
Quoted 14 lines
Quoted 13 lines
drivers/s390/cio/vfio_ccw_trace.h +7
-0+ __entry->cssid, + __entry->ssid, + __entry->sch_no, + __entry->command, + __entry->errno) +); + TRACE_EVENT(vfio_ccw_fsm_event, TP_PROTO(struct subchannel_id schid, int state, int event), TP_ARGS(schid, state, event),
Eric Farman
maintainerPATCH v2 4/4 vfio-ccw: Rework the io_fctl trace
In reply to Eric FarmanUsing __field_struct for the schib is convenient, but it doesn't appear to let us filter based on any of the schib elements. Specifying, the full schid or any element within it results in various errors by the parser. So, expand that out to its component elements, so we can limit the trace to a single device.
While we are at it, rename this trace to the function name, so we remember what is being traced instead of an abstract reference to the function control bit of the SCSW.
--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++-- drivers/s390/cio/vfio_ccw_trace.c | 2 +- drivers/s390/cio/vfio_ccw_trace.h | 18 +++++++++++------- 3 files changed, 14 insertions(+), 10 deletions(-)
drivers/s390/cio/vfio_ccw_fsm.c +2 -2
@@ -318,8 +318,8 @@ static void fsm_io_request(struct vfio_ccw_private *private, } err_out: -trace_vfio_ccw_io_fctl (scsw->cmd.fctl, schid, - io_region->ret_code, errstr); +trace_vfio_ccw_fsm_io_request (scsw->cmd.fctl, schid, + io_region->ret_code, errstr); }/*
drivers/s390/cio/vfio_ccw_trace.c +1 -1
@@ -11,4 +11,4 @@EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_async_request);EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_event); -EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_io_fctl); +EXPORT_TRACEPOINT_SYMBOL (vfio_ccw_fsm_io_request);
drivers/s390/cio/vfio_ccw_trace.h +11 -7
@@ -73,28 +73,32 @@ TRACE_EVENT(vfio_ccw_fsm_event, __entry->event) ); -TRACE_EVENT (vfio_ccw_io_fctl, +TRACE_EVENT (vfio_ccw_fsm_io_request, TP_PROTO(int fctl, struct subchannel_id schid, int errno, char *errstr),TP_ARGS (fctl, schid, errno, errstr),TP_STRUCT__entry ( + __field(u8, cssid) + __field(u8, ssid) + __field(u16, sch_no) __field(int, fctl) - __field_struct(struct subchannel_id, schid) __field(int, errno) __field(char*, errstr) ),TP_fast_assign ( + __entry->cssid = schid.cssid; + __entry->ssid = schid.ssid; + __entry->sch_no = schid.sch_no; __entry->fctl = fctl; - __entry->schid = schid; __entry->errno = errno; __entry->errstr = errstr; ), -TP_printk ("schid=%x.%x.%04x fctl=%x errno=%d info=%s" , - __entry->schid.cssid, - __entry->schid.ssid, - __entry->schid.sch_no, +TP_printk ("schid=%x.%x.%04x fctl=0x%x errno=%d info=%s" , + __entry->cssid, + __entry->ssid, + __entry->sch_no, __entry->fctl, __entry->errno, __entry->errstr)
Signature · 1 line
2.17.1
Re: [PATCH v2 4/4] vfio-ccw: Rework the io_fctl trace
Quoted 3 lines · On Wed, 16 Oct 2019 03:58:22 +0200 Eric Farman <[email protected]> wrote:
Using
__field_structfor the schib is convenient, but it doesn't appear to let us filter based on any of the schib elements. Specifying, the full schid or any element within it results
s/Specifying,/Specifying/
Quoted 7 lines
in various errors by the parser. So, expand that out to its component elements, so we can limit the trace to a single device.
While we are at it, rename this trace to the function name, so we remember what is being traced instead of an abstract reference to the function control bit of the SCSW.
Quoted 6 lines
Signed-off-by Eric Farman <[email protected]>--- drivers/s390/cio/vfio_ccw_fsm.c | 4 ++-- drivers/s390/cio/vfio_ccw_trace.c | 2 +- drivers/s390/cio/vfio_ccw_trace.h | 18 +++++++++++------- 3 files changed, 14 insertions(+), 10 deletions(-)