[linux,dev-4.10,04/16] fsi: occ: Add tracepoints

The OCC driver uses a workqueue to manage calls through to the SBEFIFO, which
in turn uses a timer callback to execute FIFO transfers. To ease observation of
end-to-end interactions e.g. from userspace `cat`ing an OCC hwmon attribute,
add tracing to book-end SBEFIFO transfers. This provides some perspective on
the time taken for a single OCC operation to take place.

Signed-off-by: Andrew Jeffery <andrew@aj.id.au>
---
 drivers/fsi/occ.c          |  9 +++++
 include/trace/events/occ.h | 86 ++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 95 insertions(+)
 create mode 100644 include/trace/events/occ.h

On 02/15/2018 06:35 AM, Andrew Jeffery wrote:
> The OCC driver uses a workqueue to manage calls through to the SBEFIFO, which
> in turn uses a timer callback to execute FIFO transfers. To ease observation of
> end-to-end interactions e.g. from userspace `cat`ing an OCC hwmon attribute,
> add tracing to book-end SBEFIFO transfers. This provides some perspective on
> the time taken for a single OCC operation to take place.

Acked-by: Eddie James <eajames@linux.vnet.ibm.com>

>
> Signed-off-by: Andrew Jeffery <andrew@aj.id.au>
> ---
>   drivers/fsi/occ.c          |  9 +++++
>   include/trace/events/occ.h | 86 ++++++++++++++++++++++++++++++++++++++++++++++
>   2 files changed, 95 insertions(+)
>   create mode 100644 include/trace/events/occ.h
>
> diff --git a/drivers/fsi/occ.c b/drivers/fsi/occ.c
> index adc64f3fcd0a..2313b6235ba3 100644
> --- a/drivers/fsi/occ.c
> +++ b/drivers/fsi/occ.c
> @@ -30,6 +30,9 @@
>   #include <linux/wait.h>
>   #include <linux/workqueue.h>
>
> +#define CREATE_TRACE_POINTS
> +#include <trace/events/occ.h>
> +
>   #define OCC_SRAM_BYTES		4096
>   #define OCC_CMD_DATA_BYTES	4090
>   #define OCC_RESP_DATA_BYTES	4089
> @@ -131,6 +134,8 @@ static int occ_enqueue_xfr(struct occ_xfr *xfr)
>
>   	spin_unlock_irq(&occ->list_lock);
>
> +	trace_occ_enq_xfer(client, xfr);
> +
>   	if (empty)
>   		queue_work(occ_wq, &occ->work);
>
> @@ -275,6 +280,7 @@ static ssize_t occ_read_common(struct occ_client *client, char __user *ubuf,
>
>   done:
>   	spin_unlock_irq(&client->lock);
> +	trace_occ_read_complete(client, xfr);
>   	occ_put_client(client);
>   	return rc;
>   }
> @@ -305,6 +311,7 @@ static ssize_t occ_write_common(struct occ_client *client,
>   	occ_get_client(client);
>   	xfr = &client->xfr;
>
> +	trace_occ_write_begin(client, xfr);
>   	spin_lock_irq(&client->lock);
>
>   	if (test_bit(CLIENT_XFR_PENDING, &client->flags)) {
> @@ -633,6 +640,7 @@ static void occ_worker(struct work_struct *work)
>   	set_bit(XFR_IN_PROGRESS, &xfr->flags);
>
>   	spin_unlock_irq(&occ->list_lock);
> +	trace_occ_worker_xfer_begin(client, xfr);
>   	mutex_lock(&occ->occ_lock);
>
>   	start = jiffies;
> @@ -695,6 +703,7 @@ static void occ_worker(struct work_struct *work)
>   	spin_unlock_irq(&occ->list_lock);
>
>   	wake_up_interruptible(&client->wait);
> +	trace_occ_worker_xfer_complete(client, xfr);
>   	occ_put_client(client);
>
>   	if (!empty)
> diff --git a/include/trace/events/occ.h b/include/trace/events/occ.h
> new file mode 100644
> index 000000000000..81395ca32ee0
> --- /dev/null
> +++ b/include/trace/events/occ.h
> @@ -0,0 +1,86 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM occ
> +
> +#if !defined(_TRACE_TIMER_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_OCC_H
> +
> +#include <linux/tracepoint.h>
> +#include <linux/occ.h>
> +
> +TRACE_EVENT(occ_enq_xfer,
> +	TP_PROTO(const void *client, const void *xfer),
> +	TP_ARGS(client, xfer),
> +	TP_STRUCT__entry(
> +		__field(const void *, client)
> +		__field(const void *, xfer)
> +	),
> +	TP_fast_assign(
> +		__entry->client = client;
> +		__entry->xfer = xfer;
> +	),
> +	TP_printk("Client %p enqueued xfer %p", __entry->client, __entry->xfer)
> +);
> +
> +TRACE_EVENT(occ_read_complete,
> +	TP_PROTO(const void *client, const void *xfer),
> +	TP_ARGS(client, xfer),
> +	TP_STRUCT__entry(
> +		__field(const void *, client)
> +		__field(const void *, xfer)
> +	),
> +	TP_fast_assign(
> +		__entry->client = client;
> +		__entry->xfer = xfer;
> +	),
> +	TP_printk("Client %p completed read for xfer %p",
> +		__entry->client, __entry->xfer)
> +);
> +
> +TRACE_EVENT(occ_write_begin,
> +	TP_PROTO(const void *client, const void *xfer),
> +	TP_ARGS(client, xfer),
> +	TP_STRUCT__entry(
> +		__field(const void *, client)
> +		__field(const void *, xfer)
> +	),
> +	TP_fast_assign(
> +		__entry->client = client;
> +		__entry->xfer = xfer;
> +	),
> +	TP_printk("Client %p began write for xfer %p",
> +		__entry->client, __entry->xfer)
> +);
> +
> +TRACE_EVENT(occ_worker_xfer_begin,
> +	TP_PROTO(const void *client, const void *xfer),
> +	TP_ARGS(client, xfer),
> +	TP_STRUCT__entry(
> +		__field(const void *, client)
> +		__field(const void *, xfer)
> +	),
> +	TP_fast_assign(
> +		__entry->client = client;
> +		__entry->xfer = xfer;
> +	),
> +	TP_printk("OCC worker began client %p xfer %p",
> +		__entry->client, __entry->xfer)
> +);
> +
> +TRACE_EVENT(occ_worker_xfer_complete,
> +	TP_PROTO(const void *client, const void *xfer),
> +	TP_ARGS(client, xfer),
> +	TP_STRUCT__entry(
> +		__field(const void *, client)
> +		__field(const void *, xfer)
> +	),
> +	TP_fast_assign(
> +		__entry->client = client;
> +		__entry->xfer = xfer;
> +	),
> +	TP_printk("OCC worker completed client %p xfer %p",
> +		__entry->client, __entry->xfer)
> +);
> +
> +#endif
> +
> +#include <trace/define_trace.h>