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 <rostedt@goodmis.org>
> Signed-off-by: David Howells <dhowells@redhat.com>
> Reviewed-by: Steven Rostedt <rostedt@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