Re: [very-RFC 6/8] Add TSN event-tracing

[Henrik Austad]

On Sun, Jun 12, 2016 at 10:22:01PM -0400, Steven Rostedt wrote:
> On Sun, 12 Jun 2016 23:25:10 +0200
> Henrik Austad  wrote:
> 
> > > > +#include 
> > > > +#include 
> > > > +/* #include  */
> > > > +
> > > > +/* FIXME: update to TRACE_CLASS to reduce overhead */  
> > > 
> > > I'm curious to why I didn't do this now. A class would make less
> > > duplication of typing too ;-)  
> > 
> > Yeah, I found this in a really great article written by some tracing-dude, 
> > I hear he talks really, really fast!
> 
> I plead the 5th!
> 
> > 
> > https://lwn.net/Articles/381064/
> > 
> > > > +TRACE_EVENT(tsn_buffer_write,
> > > > +
> > > > +   TP_PROTO(struct tsn_link *link,
> > > > +   size_t bytes),
> > > > +
> > > > +   TP_ARGS(link, bytes),
> > > > +
> > > > +   TP_STRUCT__entry(
> > > > +   __field(u64, stream_id)
> > > > +   __field(size_t, size)
> > > > +   __field(size_t, bsize)
> > > > +   __field(size_t, size_left)
> > > > +   __field(void *, buffer)
> > > > +   __field(void *, head)
> > > > +   __field(void *, tail)
> > > > +   __field(void *, end)
> > > > +   ),
> > > > +
> > > > +   TP_fast_assign(
> > > > +   __entry->stream_id = link->stream_id;
> > > > +   __entry->size = bytes;
> > > > +   __entry->bsize = link->used_buffer_size;
> > > > +   __entry->size_left = (link->head - link->tail) % 
> > > > link->used_buffer_size;  
> > > 
> > > Move this logic into the print statement, since you save head and tail.  
> > 
> > Ok, any particular reason?
> 
> Because it removes calculations during the trace. The calculations done
> in TP_printk() are done at the time of reading the trace, and
> calculations done in TP_fast_assign() are done during the recording and
> hence adding more overhead to the trace itself.

Aha! that makes sense, thanks!
(/me goes and updates the tracing-part)

-Henrik


signature.asc
Description: Digital signature

Re: [very-RFC 6/8] Add TSN event-tracing

[Henrik Austad]

On Sun, Jun 12, 2016 at 10:22:01PM -0400, Steven Rostedt wrote:
> On Sun, 12 Jun 2016 23:25:10 +0200
> Henrik Austad  wrote:
> 
> > > > +#include 
> > > > +#include 
> > > > +/* #include  */
> > > > +
> > > > +/* FIXME: update to TRACE_CLASS to reduce overhead */  
> > > 
> > > I'm curious to why I didn't do this now. A class would make less
> > > duplication of typing too ;-)  
> > 
> > Yeah, I found this in a really great article written by some tracing-dude, 
> > I hear he talks really, really fast!
> 
> I plead the 5th!
> 
> > 
> > https://lwn.net/Articles/381064/
> > 
> > > > +TRACE_EVENT(tsn_buffer_write,
> > > > +
> > > > +   TP_PROTO(struct tsn_link *link,
> > > > +   size_t bytes),
> > > > +
> > > > +   TP_ARGS(link, bytes),
> > > > +
> > > > +   TP_STRUCT__entry(
> > > > +   __field(u64, stream_id)
> > > > +   __field(size_t, size)
> > > > +   __field(size_t, bsize)
> > > > +   __field(size_t, size_left)
> > > > +   __field(void *, buffer)
> > > > +   __field(void *, head)
> > > > +   __field(void *, tail)
> > > > +   __field(void *, end)
> > > > +   ),
> > > > +
> > > > +   TP_fast_assign(
> > > > +   __entry->stream_id = link->stream_id;
> > > > +   __entry->size = bytes;
> > > > +   __entry->bsize = link->used_buffer_size;
> > > > +   __entry->size_left = (link->head - link->tail) % 
> > > > link->used_buffer_size;  
> > > 
> > > Move this logic into the print statement, since you save head and tail.  
> > 
> > Ok, any particular reason?
> 
> Because it removes calculations during the trace. The calculations done
> in TP_printk() are done at the time of reading the trace, and
> calculations done in TP_fast_assign() are done during the recording and
> hence adding more overhead to the trace itself.

Aha! that makes sense, thanks!
(/me goes and updates the tracing-part)

-Henrik


signature.asc
Description: Digital signature

Re: [very-RFC 6/8] Add TSN event-tracing

[Steven Rostedt]

On Sun, 12 Jun 2016 23:25:10 +0200
Henrik Austad  wrote:

> > > +#include 
> > > +#include 
> > > +/* #include  */
> > > +
> > > +/* FIXME: update to TRACE_CLASS to reduce overhead */  
> > 
> > I'm curious to why I didn't do this now. A class would make less
> > duplication of typing too ;-)  
> 
> Yeah, I found this in a really great article written by some tracing-dude, 
> I hear he talks really, really fast!

I plead the 5th!

> 
> https://lwn.net/Articles/381064/
> 
> > > +TRACE_EVENT(tsn_buffer_write,
> > > +
> > > + TP_PROTO(struct tsn_link *link,
> > > + size_t bytes),
> > > +
> > > + TP_ARGS(link, bytes),
> > > +
> > > + TP_STRUCT__entry(
> > > + __field(u64, stream_id)
> > > + __field(size_t, size)
> > > + __field(size_t, bsize)
> > > + __field(size_t, size_left)
> > > + __field(void *, buffer)
> > > + __field(void *, head)
> > > + __field(void *, tail)
> > > + __field(void *, end)
> > > + ),
> > > +
> > > + TP_fast_assign(
> > > + __entry->stream_id = link->stream_id;
> > > + __entry->size = bytes;
> > > + __entry->bsize = link->used_buffer_size;
> > > + __entry->size_left = (link->head - link->tail) % 
> > > link->used_buffer_size;  
> > 
> > Move this logic into the print statement, since you save head and tail.  
> 
> Ok, any particular reason?

Because it removes calculations during the trace. The calculations done
in TP_printk() are done at the time of reading the trace, and
calculations done in TP_fast_assign() are done during the recording and
hence adding more overhead to the trace itself.


> 
> > > + __entry->buffer = link->buffer;
> > > + __entry->head = link->head;
> > > + __entry->tail = link->tail;
> > > + __entry->end = link->end;
> > > + ),
> > > +
> > > + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > > [buffer=%p, head=%p, tail=%p, end=%p]",
> > > + __entry->stream_id, __entry->size, __entry->bsize, 
> > > __entry->size_left,  
> > 
> >  __entry->stream_id, __entry->size, __entry->bsize,
> >  (__entry->head - __entry->tail) % __entry->bsize,
> >   
> 
> Ok, so is this about saving space by dropping one intermediate value, or is 
> it some other point I'm missing here?

Nope, just moving the overhead from the recording of the trace to the
reading of the trace.

> 
> > > + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > > +
> > > + );
> > > +


> > > +
> > > + TP_fast_assign(
> > > + __entry->stream_id = link->stream_id;
> > > + __entry->vlan_tag = (skb_vlan_tag_present(skb) ? 
> > > skb_vlan_tag_get(skb) : 0);
> > > + __entry->bytes = bytes;
> > > + __entry->data_len = skb->data_len;
> > > + __entry->headlen = skb_headlen(skb);
> > > + __entry->protocol = ntohs(vlan_get_protocol(skb));  
> > 
> > Maybe it would be better to do the ntohs() in the TP_printk() as well.
> >   
> > > + __entry->prot_native = ntohs(skb->protocol);  
> > 
> > here too.
> >   
> > > + __entry->tx_idx = skb_get_queue_mapping(skb);
> > > +
> > > + __entry->mac_len = skb->mac_len;
> > > + __entry->hdr_len = skb->hdr_len;
> > > + __entry->vlan_tci = skb->vlan_tci;
> > > + __entry->mac_header = skb->mac_header;
> > > + __entry->tail = (unsigned int)skb->tail;
> > > + __entry->end  = (unsigned int)skb->end;
> > > + __entry->truesize = skb->truesize;
> > > + ),
> > > +
> > > + 
> > > TP_printk("stream_id=%llu,vlan_tag=0x%04x,data_size=%zd,data_len=%zd,headlen=%u,proto=0x%04x
> > >  
> > > (0x%04x),tx_idx=%d,mac_len=%u,hdr_len=%u,vlan_tci=0x%02x,mac_header=0x%02x,tail=%u,end=%u,truesize=%u",
> > > + __entry->stream_id,
> > > + __entry->vlan_tag,
> > > + __entry->bytes,
> > > + __entry->data_len,
> > > + __entry->headlen,
> > > + __entry->protocol,
> > > + __entry->prot_native, __entry->tx_idx,
> > > + __entry->mac_len,
> > > + __entry->hdr_len,
> > > + __entry->vlan_tci,
> > > + __entry->mac_header,  
> > 
> > Is this an ether mac header? If so we support %M. But as it's defined
> > as only u16, it doesn't seem like it can be.  
> 
> Actually, looking at the output, I'm not quite sure what it is that I 
> wanted to grab with that, the skb->mac_header should give an offset into 
> the header-area of skb, so it should be a constant offset from skb->head 
> (that is an actual pointer).
> 
> I *think* I wanted to make sure I updated things correctly so that the 
> offset didn't suddenly change, but the fact that I'm no longer sure 
> indicates that I should just drop that one. That whole printout is too long 
> anyway..
> 
> Thanks for pointing a finger at this!
> 
> 
> I'm still a bit stymied as to why logic should be in TP_printk() and not 
> TP_fast_assign(). Not that I really 

Re: [very-RFC 6/8] Add TSN event-tracing

[Steven Rostedt]

On Sun, 12 Jun 2016 23:25:10 +0200
Henrik Austad  wrote:

> > > +#include 
> > > +#include 
> > > +/* #include  */
> > > +
> > > +/* FIXME: update to TRACE_CLASS to reduce overhead */  
> > 
> > I'm curious to why I didn't do this now. A class would make less
> > duplication of typing too ;-)  
> 
> Yeah, I found this in a really great article written by some tracing-dude, 
> I hear he talks really, really fast!

I plead the 5th!

> 
> https://lwn.net/Articles/381064/
> 
> > > +TRACE_EVENT(tsn_buffer_write,
> > > +
> > > + TP_PROTO(struct tsn_link *link,
> > > + size_t bytes),
> > > +
> > > + TP_ARGS(link, bytes),
> > > +
> > > + TP_STRUCT__entry(
> > > + __field(u64, stream_id)
> > > + __field(size_t, size)
> > > + __field(size_t, bsize)
> > > + __field(size_t, size_left)
> > > + __field(void *, buffer)
> > > + __field(void *, head)
> > > + __field(void *, tail)
> > > + __field(void *, end)
> > > + ),
> > > +
> > > + TP_fast_assign(
> > > + __entry->stream_id = link->stream_id;
> > > + __entry->size = bytes;
> > > + __entry->bsize = link->used_buffer_size;
> > > + __entry->size_left = (link->head - link->tail) % 
> > > link->used_buffer_size;  
> > 
> > Move this logic into the print statement, since you save head and tail.  
> 
> Ok, any particular reason?

Because it removes calculations during the trace. The calculations done
in TP_printk() are done at the time of reading the trace, and
calculations done in TP_fast_assign() are done during the recording and
hence adding more overhead to the trace itself.


> 
> > > + __entry->buffer = link->buffer;
> > > + __entry->head = link->head;
> > > + __entry->tail = link->tail;
> > > + __entry->end = link->end;
> > > + ),
> > > +
> > > + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > > [buffer=%p, head=%p, tail=%p, end=%p]",
> > > + __entry->stream_id, __entry->size, __entry->bsize, 
> > > __entry->size_left,  
> > 
> >  __entry->stream_id, __entry->size, __entry->bsize,
> >  (__entry->head - __entry->tail) % __entry->bsize,
> >   
> 
> Ok, so is this about saving space by dropping one intermediate value, or is 
> it some other point I'm missing here?

Nope, just moving the overhead from the recording of the trace to the
reading of the trace.

> 
> > > + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > > +
> > > + );
> > > +


> > > +
> > > + TP_fast_assign(
> > > + __entry->stream_id = link->stream_id;
> > > + __entry->vlan_tag = (skb_vlan_tag_present(skb) ? 
> > > skb_vlan_tag_get(skb) : 0);
> > > + __entry->bytes = bytes;
> > > + __entry->data_len = skb->data_len;
> > > + __entry->headlen = skb_headlen(skb);
> > > + __entry->protocol = ntohs(vlan_get_protocol(skb));  
> > 
> > Maybe it would be better to do the ntohs() in the TP_printk() as well.
> >   
> > > + __entry->prot_native = ntohs(skb->protocol);  
> > 
> > here too.
> >   
> > > + __entry->tx_idx = skb_get_queue_mapping(skb);
> > > +
> > > + __entry->mac_len = skb->mac_len;
> > > + __entry->hdr_len = skb->hdr_len;
> > > + __entry->vlan_tci = skb->vlan_tci;
> > > + __entry->mac_header = skb->mac_header;
> > > + __entry->tail = (unsigned int)skb->tail;
> > > + __entry->end  = (unsigned int)skb->end;
> > > + __entry->truesize = skb->truesize;
> > > + ),
> > > +
> > > + 
> > > TP_printk("stream_id=%llu,vlan_tag=0x%04x,data_size=%zd,data_len=%zd,headlen=%u,proto=0x%04x
> > >  
> > > (0x%04x),tx_idx=%d,mac_len=%u,hdr_len=%u,vlan_tci=0x%02x,mac_header=0x%02x,tail=%u,end=%u,truesize=%u",
> > > + __entry->stream_id,
> > > + __entry->vlan_tag,
> > > + __entry->bytes,
> > > + __entry->data_len,
> > > + __entry->headlen,
> > > + __entry->protocol,
> > > + __entry->prot_native, __entry->tx_idx,
> > > + __entry->mac_len,
> > > + __entry->hdr_len,
> > > + __entry->vlan_tci,
> > > + __entry->mac_header,  
> > 
> > Is this an ether mac header? If so we support %M. But as it's defined
> > as only u16, it doesn't seem like it can be.  
> 
> Actually, looking at the output, I'm not quite sure what it is that I 
> wanted to grab with that, the skb->mac_header should give an offset into 
> the header-area of skb, so it should be a constant offset from skb->head 
> (that is an actual pointer).
> 
> I *think* I wanted to make sure I updated things correctly so that the 
> offset didn't suddenly change, but the fact that I'm no longer sure 
> indicates that I should just drop that one. That whole printout is too long 
> anyway..
> 
> Thanks for pointing a finger at this!
> 
> 
> I'm still a bit stymied as to why logic should be in TP_printk() and not 
> TP_fast_assign(). Not that I really have any 

Re: [very-RFC 6/8] Add TSN event-tracing

[Henrik Austad]

On Sun, Jun 12, 2016 at 12:58:03PM -0400, Steven Rostedt wrote:
> On Sun, 12 Jun 2016 01:01:34 +0200
> Henrik Austad  wrote:
> 
> > From: Henrik Austad 
> > 
> > This needs refactoring and should be updated to use TRACE_CLASS, but for
> > now it provides a fair debug-window into TSN.
> > 
> > Cc: "David S. Miller" 
> > Cc: Steven Rostedt  (maintainer:TRACING)
> > Cc: Ingo Molnar  (maintainer:TRACING)
> > Signed-off-by: Henrik Austad 
> > ---
> >  include/trace/events/tsn.h | 349 
> > +
> >  1 file changed, 349 insertions(+)
> >  create mode 100644 include/trace/events/tsn.h
> > 
> > diff --git a/include/trace/events/tsn.h b/include/trace/events/tsn.h
> > new file mode 100644
> > index 000..ac1f31b
> > --- /dev/null
> > +++ b/include/trace/events/tsn.h
> > @@ -0,0 +1,349 @@
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM tsn
> > +
> > +#if !defined(_TRACE_TSN_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_TSN_H
> > +
> > +#include 
> > +#include 
> > +
> > +#include 
> > +#include 
> > +/* #include  */
> > +
> > +/* FIXME: update to TRACE_CLASS to reduce overhead */
> 
> I'm curious to why I didn't do this now. A class would make less
> duplication of typing too ;-)

Yeah, I found this in a really great article written by some tracing-dude, 
I hear he talks really, really fast!

https://lwn.net/Articles/381064/

> > +TRACE_EVENT(tsn_buffer_write,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> > +   __entry->stream_id = link->stream_id;
> > +   __entry->size = bytes;
> > +   __entry->bsize = link->used_buffer_size;
> > +   __entry->size_left = (link->head - link->tail) % 
> > link->used_buffer_size;
> 
> Move this logic into the print statement, since you save head and tail.

Ok, any particular reason?

> > +   __entry->buffer = link->buffer;
> > +   __entry->head = link->head;
> > +   __entry->tail = link->tail;
> > +   __entry->end = link->end;
> > +   ),
> > +
> > +   TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > [buffer=%p, head=%p, tail=%p, end=%p]",
> > +   __entry->stream_id, __entry->size, __entry->bsize, 
> > __entry->size_left,
> 
>  __entry->stream_id, __entry->size, __entry->bsize,
>  (__entry->head - __entry->tail) % __entry->bsize,
> 

Ok, so is this about saving space by dropping one intermediate value, or is 
it some other point I'm missing here?

> > +   __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > +
> > +   );
> > +
> > +TRACE_EVENT(tsn_buffer_write_net,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> > +   __entry->stream_id = link->stream_id;
> > +   __entry->size = bytes;
> > +   __entry->bsize = link->used_buffer_size;
> > +   __entry->size_left = (link->head - link->tail) % 
> > link->used_buffer_size;
> > +   __entry->buffer = link->buffer;
> > +   __entry->head = link->head;
> > +   __entry->tail = link->tail;
> > +   __entry->end = link->end;
> > +   ),
> > +
> > +   TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > [buffer=%p, head=%p, tail=%p, end=%p]",
> > +   __entry->stream_id, __entry->size, __entry->bsize, 
> > __entry->size_left,
> > +   __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > +
> > +   );
> > +
> > +
> > +TRACE_EVENT(tsn_buffer_read,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> 

Re: [very-RFC 6/8] Add TSN event-tracing

[Henrik Austad]

On Sun, Jun 12, 2016 at 12:58:03PM -0400, Steven Rostedt wrote:
> On Sun, 12 Jun 2016 01:01:34 +0200
> Henrik Austad  wrote:
> 
> > From: Henrik Austad 
> > 
> > This needs refactoring and should be updated to use TRACE_CLASS, but for
> > now it provides a fair debug-window into TSN.
> > 
> > Cc: "David S. Miller" 
> > Cc: Steven Rostedt  (maintainer:TRACING)
> > Cc: Ingo Molnar  (maintainer:TRACING)
> > Signed-off-by: Henrik Austad 
> > ---
> >  include/trace/events/tsn.h | 349 
> > +
> >  1 file changed, 349 insertions(+)
> >  create mode 100644 include/trace/events/tsn.h
> > 
> > diff --git a/include/trace/events/tsn.h b/include/trace/events/tsn.h
> > new file mode 100644
> > index 000..ac1f31b
> > --- /dev/null
> > +++ b/include/trace/events/tsn.h
> > @@ -0,0 +1,349 @@
> > +#undef TRACE_SYSTEM
> > +#define TRACE_SYSTEM tsn
> > +
> > +#if !defined(_TRACE_TSN_H) || defined(TRACE_HEADER_MULTI_READ)
> > +#define _TRACE_TSN_H
> > +
> > +#include 
> > +#include 
> > +
> > +#include 
> > +#include 
> > +/* #include  */
> > +
> > +/* FIXME: update to TRACE_CLASS to reduce overhead */
> 
> I'm curious to why I didn't do this now. A class would make less
> duplication of typing too ;-)

Yeah, I found this in a really great article written by some tracing-dude, 
I hear he talks really, really fast!

https://lwn.net/Articles/381064/

> > +TRACE_EVENT(tsn_buffer_write,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> > +   __entry->stream_id = link->stream_id;
> > +   __entry->size = bytes;
> > +   __entry->bsize = link->used_buffer_size;
> > +   __entry->size_left = (link->head - link->tail) % 
> > link->used_buffer_size;
> 
> Move this logic into the print statement, since you save head and tail.

Ok, any particular reason?

> > +   __entry->buffer = link->buffer;
> > +   __entry->head = link->head;
> > +   __entry->tail = link->tail;
> > +   __entry->end = link->end;
> > +   ),
> > +
> > +   TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > [buffer=%p, head=%p, tail=%p, end=%p]",
> > +   __entry->stream_id, __entry->size, __entry->bsize, 
> > __entry->size_left,
> 
>  __entry->stream_id, __entry->size, __entry->bsize,
>  (__entry->head - __entry->tail) % __entry->bsize,
> 

Ok, so is this about saving space by dropping one intermediate value, or is 
it some other point I'm missing here?

> > +   __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > +
> > +   );
> > +
> > +TRACE_EVENT(tsn_buffer_write_net,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> > +   __entry->stream_id = link->stream_id;
> > +   __entry->size = bytes;
> > +   __entry->bsize = link->used_buffer_size;
> > +   __entry->size_left = (link->head - link->tail) % 
> > link->used_buffer_size;
> > +   __entry->buffer = link->buffer;
> > +   __entry->head = link->head;
> > +   __entry->tail = link->tail;
> > +   __entry->end = link->end;
> > +   ),
> > +
> > +   TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> > [buffer=%p, head=%p, tail=%p, end=%p]",
> > +   __entry->stream_id, __entry->size, __entry->bsize, 
> > __entry->size_left,
> > +   __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> > +
> > +   );
> > +
> > +
> > +TRACE_EVENT(tsn_buffer_read,
> > +
> > +   TP_PROTO(struct tsn_link *link,
> > +   size_t bytes),
> > +
> > +   TP_ARGS(link, bytes),
> > +
> > +   TP_STRUCT__entry(
> > +   __field(u64, stream_id)
> > +   __field(size_t, size)
> > +   __field(size_t, bsize)
> > +   __field(size_t, size_left)
> > +   __field(void *, buffer)
> > +   __field(void *, head)
> > +   __field(void *, tail)
> > +   __field(void *, end)
> > +   ),
> > +
> > +   TP_fast_assign(
> > +   __entry->stream_id = link->stream_id;
> > +   __entry->size = bytes;
> > +   

Re: [very-RFC 6/8] Add TSN event-tracing

[Steven Rostedt]

On Sun, 12 Jun 2016 01:01:34 +0200
Henrik Austad  wrote:

> From: Henrik Austad 
> 
> This needs refactoring and should be updated to use TRACE_CLASS, but for
> now it provides a fair debug-window into TSN.
> 
> Cc: "David S. Miller" 
> Cc: Steven Rostedt  (maintainer:TRACING)
> Cc: Ingo Molnar  (maintainer:TRACING)
> Signed-off-by: Henrik Austad 
> ---
>  include/trace/events/tsn.h | 349 
> +
>  1 file changed, 349 insertions(+)
>  create mode 100644 include/trace/events/tsn.h
> 
> diff --git a/include/trace/events/tsn.h b/include/trace/events/tsn.h
> new file mode 100644
> index 000..ac1f31b
> --- /dev/null
> +++ b/include/trace/events/tsn.h
> @@ -0,0 +1,349 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM tsn
> +
> +#if !defined(_TRACE_TSN_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_TSN_H
> +
> +#include 
> +#include 
> +
> +#include 
> +#include 
> +/* #include  */
> +
> +/* FIXME: update to TRACE_CLASS to reduce overhead */

I'm curious to why I didn't do this now. A class would make less
duplication of typing too ;-)

> +TRACE_EVENT(tsn_buffer_write,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;

Move this logic into the print statement, since you save head and tail.

> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> [buffer=%p, head=%p, tail=%p, end=%p]",
> + __entry->stream_id, __entry->size, __entry->bsize, 
> __entry->size_left,

 __entry->stream_id, __entry->size, __entry->bsize,
 (__entry->head - __entry->tail) % __entry->bsize,

> + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> +
> + );
> +
> +TRACE_EVENT(tsn_buffer_write_net,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;
> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> [buffer=%p, head=%p, tail=%p, end=%p]",
> + __entry->stream_id, __entry->size, __entry->bsize, 
> __entry->size_left,
> + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> +
> + );
> +
> +
> +TRACE_EVENT(tsn_buffer_read,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;
> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, 

Re: [very-RFC 6/8] Add TSN event-tracing

[Steven Rostedt]

On Sun, 12 Jun 2016 01:01:34 +0200
Henrik Austad  wrote:

> From: Henrik Austad 
> 
> This needs refactoring and should be updated to use TRACE_CLASS, but for
> now it provides a fair debug-window into TSN.
> 
> Cc: "David S. Miller" 
> Cc: Steven Rostedt  (maintainer:TRACING)
> Cc: Ingo Molnar  (maintainer:TRACING)
> Signed-off-by: Henrik Austad 
> ---
>  include/trace/events/tsn.h | 349 
> +
>  1 file changed, 349 insertions(+)
>  create mode 100644 include/trace/events/tsn.h
> 
> diff --git a/include/trace/events/tsn.h b/include/trace/events/tsn.h
> new file mode 100644
> index 000..ac1f31b
> --- /dev/null
> +++ b/include/trace/events/tsn.h
> @@ -0,0 +1,349 @@
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM tsn
> +
> +#if !defined(_TRACE_TSN_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_TSN_H
> +
> +#include 
> +#include 
> +
> +#include 
> +#include 
> +/* #include  */
> +
> +/* FIXME: update to TRACE_CLASS to reduce overhead */

I'm curious to why I didn't do this now. A class would make less
duplication of typing too ;-)

> +TRACE_EVENT(tsn_buffer_write,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;

Move this logic into the print statement, since you save head and tail.

> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> [buffer=%p, head=%p, tail=%p, end=%p]",
> + __entry->stream_id, __entry->size, __entry->bsize, 
> __entry->size_left,

 __entry->stream_id, __entry->size, __entry->bsize,
 (__entry->head - __entry->tail) % __entry->bsize,

> + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> +
> + );
> +
> +TRACE_EVENT(tsn_buffer_write_net,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;
> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> [buffer=%p, head=%p, tail=%p, end=%p]",
> + __entry->stream_id, __entry->size, __entry->bsize, 
> __entry->size_left,
> + __entry->buffer,__entry->head, __entry->tail,  __entry->end)
> +
> + );
> +
> +
> +TRACE_EVENT(tsn_buffer_read,
> +
> + TP_PROTO(struct tsn_link *link,
> + size_t bytes),
> +
> + TP_ARGS(link, bytes),
> +
> + TP_STRUCT__entry(
> + __field(u64, stream_id)
> + __field(size_t, size)
> + __field(size_t, bsize)
> + __field(size_t, size_left)
> + __field(void *, buffer)
> + __field(void *, head)
> + __field(void *, tail)
> + __field(void *, end)
> + ),
> +
> + TP_fast_assign(
> + __entry->stream_id = link->stream_id;
> + __entry->size = bytes;
> + __entry->bsize = link->used_buffer_size;
> + __entry->size_left = (link->head - link->tail) % 
> link->used_buffer_size;
> + __entry->buffer = link->buffer;
> + __entry->head = link->head;
> + __entry->tail = link->tail;
> + __entry->end = link->end;
> + ),
> +
> + TP_printk("stream_id=%llu, copy=%zd, buffer: %zd, avail=%zd, 
> [buffer=%p, head=%p, tail=%p, end=%p]",
> + __entry->stream_id, __entry->size, __entry->bsize, 
>