[PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Zoltan Kiss]

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@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

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Steven Rostedt]

On Thu, 22 Aug 2013 22:47:28 +0100
Zoltan Kiss <zoltan.kiss@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;

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Konrad Rzeszutek Wilk]

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@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
> 

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Zoltan Kiss]

On 23/08/13 13:55, Konrad Rzeszutek Wilk wrote:
> 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?

You mean instead of drivers/xen/swiotlb-xen.c ? This is a Xen SWIOTLB 
specific thing, it will hit exactly at the point when double buffering 
becomes sure - under Xen.
But I can rename the tracer and call trace_bounced in swiotlb_map_page 
as well, so it can be used for normal SWIOTLB bounce tracing as well. Is 
it OK for you?

Regards,

Zoli

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Konrad Rzeszutek Wilk]

On Mon, Sep 02, 2013 at 06:54:30PM +0100, Zoltan Kiss wrote:
> On 23/08/13 13:55, Konrad Rzeszutek Wilk wrote:
> >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?
> 
> You mean instead of drivers/xen/swiotlb-xen.c ? This is a Xen
> SWIOTLB specific thing, it will hit exactly at the point when double
> buffering becomes sure - under Xen.

Correct. The double buffering code is being run in lib/swiotlb.c not the
xen-swiotlb.c. Hence the question of why not move the tracing in there.

> But I can rename the tracer and call trace_bounced in
> swiotlb_map_page as well, so it can be used for normal SWIOTLB
> bounce tracing as well. Is it OK for you?

Yes. And please (if it adds a benefit) also for unmap/sync which can trigger
the bounce buffer.

Or if it makes sense just for the bounce buffer copying - then just
leave it at that. Thanks.
> 
> Regards,
> 
> Zoli

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Zoltan Kiss]

On 22/08/13 23:02, Steven Rostedt wrote:
> 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.

Sure, see my v2 patch coming soon.

Zoli

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Zoltan Kiss]

On 03/09/13 13:42, Konrad Rzeszutek Wilk wrote:
> Correct. The double buffering code is being run in lib/swiotlb.c not the
> xen-swiotlb.c. Hence the question of why not move the tracing in there.
I've put the trace to both locations before swiotlb_tbl_map_single is 
called, so the same tracer will be hit both with classic and Xen 
SWIOTLB. I used 2 different place instead of calling from 
swiotlb_tbl_map_single because I want to print out dev_addr, and it's 
calculated differently.

> Yes. And please (if it adds a benefit) also for unmap/sync which can trigger
> the bounce buffer.
>
> Or if it makes sense just for the bounce buffer copying - then just
> leave it at that. Thanks.
For me the relevant event was to see when we start to do bounce 
buffering. When does it end, or when syncing happens is a different 
thing. If someone is interested, they can easily extend this patch with 
that.

However one question bothers me: why ftrace doesn't trace these 
functions? They are not inlined, static, or marked as notrace.

Regards,

Zoli

Re: [PATCH] tracing/events: Add bounce tracing to swiotbl-xen

[Konrad Rzeszutek Wilk]

On Wed, Sep 04, 2013 at 09:10:50PM +0100, Zoltan Kiss wrote:
> On 03/09/13 13:42, Konrad Rzeszutek Wilk wrote:
> >Correct. The double buffering code is being run in lib/swiotlb.c not the
> >xen-swiotlb.c. Hence the question of why not move the tracing in there.
> I've put the trace to both locations before swiotlb_tbl_map_single
> is called, so the same tracer will be hit both with classic and Xen
> SWIOTLB. I used 2 different place instead of calling from
> swiotlb_tbl_map_single because I want to print out dev_addr, and
> it's calculated differently.
> 
> >Yes. And please (if it adds a benefit) also for unmap/sync which can trigger
> >the bounce buffer.
> >
> >Or if it makes sense just for the bounce buffer copying - then just
> >leave it at that. Thanks.
> For me the relevant event was to see when we start to do bounce
> buffering. When does it end, or when syncing happens is a different
> thing. If someone is interested, they can easily extend this patch
> with that.
> 
> However one question bothers me: why ftrace doesn't trace these
> functions? They are not inlined, static, or marked as notrace.

They are usually part of the dma_ops structure. That might be the reason.
> 
> Regards,
> 
> Zoli