Xen devel - Aug 2013 - [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

Ftrace is currently not able to detect when SWIOTLB has to do double buffering
under Xen. You can only see it indirectly in function_graph, when
xen_swiotlb_map_page() doesn't stop after range_straddles_page_boundary(),
but
calls spinlock functions, memcpy() and xen_phys_to_bus() as well. This patch
introduces the swiotlb-xen:bounced event, which also prints out the following
informations to help you find out why bouncing happened:

dev_name: 0000:08:00.0 dma_mask=ffffffffffffffff dev_addr=9149f000 size=32768
swiotlb_force=0

If (dev_addr + size + 1) > dma_mask, the buffer is out of the device's
DMA
range. If swiotlb_force == 1, you should really change the kernel parameters.
Otherwise, the buffer is not contiguous in mfn space.

Signed-off-by: Zoltan Kiss <zoltan.kiss at citrix.com>
---
 drivers/xen/swiotlb-xen.c          |    7 ++++++
 include/trace/events/swiotlb-xen.h |   46 ++++++++++++++++++++++++++++++++++++
 2 files changed, 53 insertions(+)
 create mode 100644 include/trace/events/swiotlb-xen.h

diff --git a/drivers/xen/swiotlb-xen.c b/drivers/xen/swiotlb-xen.c
index aadffcf..f08440d 100644
--- a/drivers/xen/swiotlb-xen.c
+++ b/drivers/xen/swiotlb-xen.c
@@ -42,6 +42,10 @@
 #include <xen/page.h>
 #include <xen/xen-ops.h>
 #include <xen/hvc-console.h>
+
+#define CREATE_TRACE_POINTS
+#include <trace/events/swiotlb-xen.h>
+
 /*
  * Used to do a quick range check in swiotlb_tbl_unmap_single and
  * swiotlb_tbl_sync_single_*, to see if the memory was in fact allocated by
this
@@ -358,6 +362,9 @@ dma_addr_t xen_swiotlb_map_page(struct device *dev, struct
page *page,
 	/*
 	 * Oh well, have to allocate and map a bounce buffer.
 	 */
+
+	trace_bounced(dev, dev_addr, size, swiotlb_force);
+
 	map = swiotlb_tbl_map_single(dev, start_dma_addr, phys, size, dir);
 	if (map == SWIOTLB_MAP_ERROR)
 		return DMA_ERROR_CODE;
diff --git a/include/trace/events/swiotlb-xen.h
b/include/trace/events/swiotlb-xen.h
new file mode 100644
index 0000000..cbe2dca
--- /dev/null
+++ b/include/trace/events/swiotlb-xen.h
@@ -0,0 +1,46 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM swiotlb-xen
+
+#if !defined(_TRACE_SWIOTLBXEN_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_SWIOTLBXEN_H
+
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(bounced,
+
+	TP_PROTO(struct device *dev,
+		 dma_addr_t dev_addr,
+		 size_t size,
+		 int swiotlb_force),
+
+	TP_ARGS(dev, dev_addr, size, swiotlb_force),
+
+	TP_STRUCT__entry(
+		__string(	dev_name,	dev_name(dev)	)
+		__field(	u64,	dma_mask		)
+		__field(	dma_addr_t,	dev_addr	)
+		__field(	size_t,	size			)
+		__field(	int,	swiotlb_force		)
+	),
+
+	TP_fast_assign(
+		__assign_str(dev_name, dev_name(dev));
+		__entry->dma_mask = (dev->dma_mask ? *dev->dma_mask : 0);
+		__entry->dev_addr = dev_addr;
+		__entry->size = size;
+		__entry->swiotlb_force = swiotlb_force;
+	),
+
+	TP_printk("dev_name: %s dma_mask=%llx dev_addr=%llx "
+		"size=%zu swiotlb_force=%x",
+		__get_str(dev_name),
+		__entry->dma_mask,
+		(unsigned long long)__entry->dev_addr,
+		__entry->size,
+		__entry->swiotlb_force )
+);
+
+#endif /*  _TRACE_IRQ_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
-- 
1.7.9.5

On Thu, 22 Aug 2013 22:47:28 +0100
Zoltan Kiss <zoltan.kiss at citrix.com> wrote:

>  /*
>   * Used to do a quick range check in swiotlb_tbl_unmap_single and
>   * swiotlb_tbl_sync_single_*, to see if the memory was in fact allocated
by this
> @@ -358,6 +362,9 @@ dma_addr_t xen_swiotlb_map_page(struct device *dev,
struct page *page,
>  	/*
>  	 * Oh well, have to allocate and map a bounce buffer.
>  	 */
> +
> +	trace_bounced(dev, dev_addr, size, swiotlb_force);
Please use a more specific name. "bounce" is too generic. I know
tracepoints are grouped by systems, but its easier for tools to just
state a tracepoint name than the system:event pair.

trace_xen_bounced()
 or
trace_swiotlb_bounced()

Something other than just "bounced".

Thanks!

-- Steve
> +
>  	map = swiotlb_tbl_map_single(dev, start_dma_addr, phys, size, dir);
>  	if (map == SWIOTLB_MAP_ERROR)
>  		return DMA_ERROR_CODE;

On Thu, Aug 22, 2013 at 10:47:28PM +0100, Zoltan Kiss
wrote:
> Ftrace is currently not able to detect when SWIOTLB has to do double
buffering
> under Xen. You can only see it indirectly in function_graph, when
> xen_swiotlb_map_page() doesn't stop after
range_straddles_page_boundary(), but
> calls spinlock functions, memcpy() and xen_phys_to_bus() as well. This
patch
> introduces the swiotlb-xen:bounced event, which also prints out the
following
> informations to help you find out why bouncing happened:
> 
> dev_name: 0000:08:00.0 dma_mask=ffffffffffffffff dev_addr=9149f000
size=32768
> swiotlb_force=0
> 
> If (dev_addr + size + 1) > dma_mask, the buffer is out of the
device's DMA
> range. If swiotlb_force == 1, you should really change the kernel
parameters.
> Otherwise, the buffer is not contiguous in mfn space.
Could this be in the lib/swiotlb.c instead?
> 
> Signed-off-by: Zoltan Kiss <zoltan.kiss at citrix.com>
> ---
>  drivers/xen/swiotlb-xen.c          |    7 ++++++
>  include/trace/events/swiotlb-xen.h |   46
++++++++++++++++++++++++++++++++++++
>  2 files changed, 53 insertions(+)
>  create mode 100644 include/trace/events/swiotlb-xen.h
> 
> diff --git a/drivers/xen/swiotlb-xen.c b/drivers/xen/swiotlb-xen.c
> index aadffcf..f08440d 100644
> --- a/drivers/xen/swiotlb-xen.c
> +++ b/drivers/xen/swiotlb-xen.c
> @@ -42,6 +42,10 @@
>  #include <xen/page.h>
>  #include <xen/xen-ops.h>
>  #include <xen/hvc-console.h>
> +
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/swiotlb-xen.h>
> +
>  /*
>   * Used to do a quick range check in swiotlb_tbl_unmap_single and
>   * swiotlb_tbl_sync_single_*, to see if the memory was in fact allocated
by this
> @@ -358,6 +362,9 @@ dma_addr_t xen_swiotlb_map_page(struct device *dev,
struct page *page,
>  	/*
>  	 * Oh well, have to allocate and map a bounce buffer.
>  	 */
> +
> +	trace_bounced(dev, dev_addr, size, swiotlb_force);
> +
>  	map = swiotlb_tbl_map_single(dev, start_dma_addr, phys, size, dir);
>  	if (map == SWIOTLB_MAP_ERROR)
>  		return DMA_ERROR_CODE;
> diff --git a/include/trace/events/swiotlb-xen.h
b/include/trace/events/swiotlb-xen.h
> new file mode 100644
> index 0000000..cbe2dca
> --- /dev/null
> +++ b/include/trace/events/swiotlb-xen.h
> @@ -0,0 +1,46 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM swiotlb-xen
> +
> +#if !defined(_TRACE_SWIOTLBXEN_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_SWIOTLBXEN_H
> +
> +#include <linux/tracepoint.h>
> +
> +TRACE_EVENT(bounced,
> +
> +	TP_PROTO(struct device *dev,
> +		 dma_addr_t dev_addr,
> +		 size_t size,
> +		 int swiotlb_force),
> +
> +	TP_ARGS(dev, dev_addr, size, swiotlb_force),
> +
> +	TP_STRUCT__entry(
> +		__string(	dev_name,	dev_name(dev)	)
> +		__field(	u64,	dma_mask		)
> +		__field(	dma_addr_t,	dev_addr	)
> +		__field(	size_t,	size			)
> +		__field(	int,	swiotlb_force		)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(dev_name, dev_name(dev));
> +		__entry->dma_mask = (dev->dma_mask ? *dev->dma_mask : 0);
> +		__entry->dev_addr = dev_addr;
> +		__entry->size = size;
> +		__entry->swiotlb_force = swiotlb_force;
> +	),
> +
> +	TP_printk("dev_name: %s dma_mask=%llx dev_addr=%llx "
> +		"size=%zu swiotlb_force=%x",
> +		__get_str(dev_name),
> +		__entry->dma_mask,
> +		(unsigned long long)__entry->dev_addr,
> +		__entry->size,
> +		__entry->swiotlb_force )
> +);
> +
> +#endif /*  _TRACE_IRQ_H */
> +
> +/* This part must be outside protection */
> +#include <trace/define_trace.h>
> -- 
> 1.7.9.5
>