Re: [PATCH 1/2] i2c: Add message transfer tracepoints for I2C

[Wolfram Sang]

Hi David,

On Thu, Jan 09, 2014 at 09:49:54PM +0000, David Howells wrote:
> Add tracepoints into the I2C message transfer function to retrieve the message
> sent or received.  The following config options must be turned on to make use
> of the facility:
> 
>       CONFIG_FTRACE
>       CONFIG_ENABLE_DEFAULT_TRACERS
> 
> The I2C tracepoint can be enabled thusly:
> 
>       echo 1 >/sys/kernel/debug/tracing/events/i2c/i2c_transfer/enable
> 
> and will dump messages that can be viewed in /sys/kernel/debug/tracing/trace
> that look like:
> 
>       ... i2c_write: i2c-5 #0 f=00 a=44 l=2 [0214]
>       ... i2c_read: i2c-5 #1 f=01 a=44 l=4
>       ... i2c_reply: i2c-5 #1 f=01 a=44 l=4 [33000000]
>       ... i2c_result: i2c-5 n=2 ret=2
> 
> formatted as:
> 
>       i2c-<adapter-nr>
>       #<message-array-index>
>       f=<flags>
>       a=<addr>
>       l=<datalen>
>       n=<message-array-size>
>       ret=<result>
>       [<data>]
> 
> The operation is done between the i2c_write/i2c_read lines and the i2c_reply
> and i2c_result lines so that if the hardware hangs, the trace buffer can be
> consulted to determine the problematic operation.
> 
> The adapters to be traced can be selected by something like:
> 
>       echo adapter_nr==1 >/sys/kernel/debug/tracing/events/i2c/filter
> 
> These changes are based on code from Steven Rostedt.
> 
> Signed-off-by: Steven Rostedt <rost...@goodmis.org>
> Signed-off-by: David Howells <dhowe...@redhat.com>
> Reviewed-by: Steven Rostedt <rost...@goodmis.org>

I like it very much, just have some comments about the format.

> +TRACE_EVENT_FN(i2c_write,
> +            TP_PROTO(const struct i2c_adapter *adap, const struct i2c_msg 
> *msg,
> +                     int num),
> +            TP_ARGS(adap, msg, num),
> +            TP_STRUCT__entry(
> +                    __field(int,     adapter_nr              )
> +                    __field(__u16,   msg_nr                  )
> +                    __field(__u16,   addr                    )
> +                    __field(__u16,   flags                   )
> +                    __field(__u16,   len                     )
> +                    __dynamic_array(__u8, buf, msg->len)     ),
> +            TP_fast_assign(
> +                    __entry->adapter_nr = adap->nr;
> +                    __entry->msg_nr = num;
> +                    __entry->addr = msg->addr;
> +                    __entry->flags = msg->flags;
> +                    __entry->len = msg->len;
> +                    memcpy(__get_dynamic_array(buf), msg->buf, msg->len);
> +                           ),
> +            TP_printk("i2c-%d #%u f=%02x a=%02x l=%u [%*phN]",

'flags' are u16 and the whole range is needed -> %04x

'addr' is u16 and either 7 or 10 bits are needed. The core does the
following when assigning names because it is possible to have devices
0x50 (7-bit) and 0x050 (10-bit) on the bus:

        /* For 10-bit clients, add an arbitrary offset to avoid collisions */
        dev_set_name(&client->dev, "%d-%04x", i2c_adapter_id(adap),
                     client->addr | ((client->flags & I2C_CLIENT_TEN)
                                     ? 0xa000 : 0));

I don't know if this can be implemented. Actually, I don't think it
needs to be implemented since flags are printed, too. So, with this the
10-bit case is visible and for the address simply %03x should do.

And for the buffer: %*phN is difficult to read IMO. What about %*ph? Or
%*phD at least?

Thanks,

   Wolfram

signature.asc
Description: Digital signature