From patchwork Fri Dec 16 17:59:11 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Henrik Austad X-Patchwork-Id: 706505 X-Patchwork-Delegate: davem@davemloft.net Return-Path: X-Original-To: patchwork-incoming@ozlabs.org Delivered-To: patchwork-incoming@ozlabs.org Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by ozlabs.org (Postfix) with ESMTP id 3tgJ8J1g6Kz9t2p for ; Sat, 17 Dec 2016 05:03:28 +1100 (AEDT) Authentication-Results: ozlabs.org; dkim=pass (2048-bit key; unprotected) header.d=austad-us.20150623.gappssmtp.com header.i=@austad-us.20150623.gappssmtp.com header.b="ZvLETd3+"; dkim-atps=neutral Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757551AbcLPSBA (ORCPT ); Fri, 16 Dec 2016 13:01:00 -0500 Received: from mail-lf0-f68.google.com ([209.85.215.68]:35795 "EHLO mail-lf0-f68.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756577AbcLPSAG (ORCPT ); Fri, 16 Dec 2016 13:00:06 -0500 Received: by mail-lf0-f68.google.com with SMTP id p100so1903212lfg.2 for ; Fri, 16 Dec 2016 10:00:05 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=austad-us.20150623.gappssmtp.com; s=20150623; h=from:to:cc:subject:date:message-id:in-reply-to:references; bh=EU8R/dBOxTOljKyOKcdmTL41z9kYn+dPbQ2U+gydE9g=; b=ZvLETd3+i1kb+KhbUmllOXvZvBeK1DXSy38E0waeccDL0j5kJHZZD0BvG6ujYqqJyy ORwcTUlWBMZfw9XDqF99zicRrdShd/pxm2C0/vX9pe6Ln1bze4R6XqONSuY9b/l2kI0v PleHeJo3w3hVHryDQWdhNrfEjQoVNN9HGt1vpeYmTKfjkTqO0458Vnr9ST/AJ+VX3xEJ 4Zq13VBjFdFkaX0ZSpTQ2sW+NZBhwNRWvvGItbXBiZUDXu2ltHyRZi6vfHdqLapn3/W2 mvqZCQaLhE1pKFxT4sFaQDzWL1WrtOuHHHXDAGTT2iTq6o8kwcWV/0lMItY5ue51G+7k xNDw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references; bh=EU8R/dBOxTOljKyOKcdmTL41z9kYn+dPbQ2U+gydE9g=; b=sxKsb21PT73Nb8ljLV+iBBIeTzPriAKDuvacLW3nN68wkXRyHkSndy181TRJFr/aUV l4B73QvPuK5VqgM0uhprLHxZ6YJBidvycCdwnWENcqTC5VbsFixji/95vafZJlb3g2Uc 5Dofuf9lq5L3GM1Ki7F3Cqoy45l8MA++B6CC1nw9wQrugaXkhf0gb2lZ2bO9aQez+Lx2 c6rjnXMB+lKlWLvZCSeqx1Qn6GKuIa7rdfa2QWTw+KkwpDuc7bYoyFFtgIUdCa1hW2Cv 76Ip51qZ5yBEiRI6FUPQo0/EE+lvjLFXR/sVlefwoXtv+rCTkJlSuxjLCdT7VAezHJ64 Z+gw== X-Gm-Message-State: AIkVDXLD38vxg02FNy/4edrdfIHv6U+lFDBzDTTY6N8kM4gZh0TKlee/co3WTgqMGQ8mqQ== X-Received: by 10.46.5.71 with SMTP id 68mr1618029ljf.13.1481911204875; Fri, 16 Dec 2016 10:00:04 -0800 (PST) Received: from sisyphus.home.austad.us ([51.175.50.162]) by smtp.gmail.com with ESMTPSA id 137sm1512067lfz.2.2016.12.16.10.00.03 (version=TLS1_2 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Fri, 16 Dec 2016 10:00:04 -0800 (PST) From: henrik@austad.us To: linux-kernel@vger.kernel.org Cc: Richard Cochran , henrik@austad.us, Henrik Austad , linux-media@vger.kernel.org, alsa-devel@vger.kernel.org, netdev@vger.kernel.org, "David S. Miller" , Steven Rostedt , Ingo Molnar Subject: [TSN RFC v2 7/9] Add TSN event-tracing Date: Fri, 16 Dec 2016 18:59:11 +0100 Message-Id: <1481911153-549-8-git-send-email-henrik@austad.us> X-Mailer: git-send-email 2.7.4 In-Reply-To: <1481911153-549-1-git-send-email-henrik@austad.us> References: <1481911153-549-1-git-send-email-henrik@austad.us> Sender: netdev-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: netdev@vger.kernel.org From: Henrik Austad Provide a fair debug-window into TSN. It tries to use TRACE_CLASS as much as possible and moves as much as possible of the logic into TP_printk() to minimize tracing overhead. Cc: "David S. Miller" Cc: Steven Rostedt (maintainer:TRACING) Cc: Ingo Molnar (maintainer:TRACING) Signed-off-by: Henrik Austad --- include/trace/events/tsn.h | 333 +++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 333 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 0000000..522229c --- /dev/null +++ b/include/trace/events/tsn.h @@ -0,0 +1,333 @@ +#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 */ +DECLARE_EVENT_CLASS(tsn_buffer_template, + + 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(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->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->head - __entry->tail) % __entry->bsize, + __entry->buffer, __entry->head, __entry->tail, __entry->end) +); + +DEFINE_EVENT(tsn_buffer_template, tsn_buffer_write, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + +DEFINE_EVENT(tsn_buffer_template, tsn_buffer_write_net, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + +DEFINE_EVENT(tsn_buffer_template, tsn_buffer_read, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + +DEFINE_EVENT(tsn_buffer_template, tsn_buffer_read_net, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + + +DECLARE_EVENT_CLASS(tsn_buffer_update, + + TP_PROTO(struct tsn_link *link, + size_t reported_avail), + + TP_ARGS(link, reported_avail), + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(size_t, bsize) + __field(void *, head) + __field(void *, tail) + __field(size_t, reported_left) + __field(size_t, low_water) + ), + + TP_fast_assign( + __entry->stream_id = link->stream_id; + __entry->bsize = link->used_buffer_size; + __entry->head = link->head; + __entry->tail = link->tail; + __entry->reported_left = reported_avail; + __entry->low_water = link->low_water_mark; + ), + + TP_printk("stream_id=%llu, buffer_size=%zd, avail=%zd, reported=%zd, low_water=%zd", + __entry->stream_id, __entry->bsize, + (__entry->head - __entry->tail) % __entry->bsize, + __entry->reported_left, __entry->low_water) +); + +/* Bytes will be "reported left", i.e. how much more space we have in + * the buffer before we wrap. + */ +DEFINE_EVENT(tsn_buffer_update, tsn_refill, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + +DEFINE_EVENT(tsn_buffer_update, tsn_buffer_drain, + TP_PROTO(struct tsn_link *link, size_t bytes), + TP_ARGS(link, bytes) +); + +TRACE_EVENT(tsn_send_batch, + + TP_PROTO(struct tsn_link *link, + int num_send, + u64 ts_base_ns, + u64 ts_delta_ns), + + TP_ARGS(link, num_send, ts_base_ns, ts_delta_ns), + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(int, seqnr) + __field(int, num_send) + __field(u64, ts_base_ns) + __field(u64, ts_delta_ns) + ), + + TP_fast_assign( + __entry->stream_id = link->stream_id; + __entry->seqnr = (int)link->last_seqnr; + __entry->ts_base_ns = ts_base_ns; + __entry->ts_delta_ns = ts_delta_ns; + __entry->num_send = num_send; + ), + + TP_printk("stream_id=%llu, seqnr=%d, num_send=%d, ts_base_ns=%llu, ts_delta_ns=%llu", + __entry->stream_id, __entry->seqnr, __entry->num_send, __entry->ts_base_ns, __entry->ts_delta_ns) +); + +TRACE_EVENT(tsn_rx_handler, + + TP_PROTO(struct tsn_link *link, + const struct ethhdr *ethhdr, + u64 sid), + + TP_ARGS(link, ethhdr, sid), + + TP_STRUCT__entry( + __field(char *, name) + __field(u16, proto) + __field(u64, sid) + __field(u64, link_sid) + ), + TP_fast_assign( + __entry->name = link->nic->name; + __entry->proto = ethhdr->h_proto; + __entry->sid = sid; + __entry->link_sid = link->stream_id; + ), + + TP_printk("name=%s, proto: 0x%04x, stream_id=%llu, link->sid=%llu", + __entry->name, ntohs(__entry->proto), __entry->sid, __entry->link_sid) +); + +TRACE_EVENT(tsn_du, + + TP_PROTO(struct tsn_link *link, + size_t bytes), + + TP_ARGS(link, bytes), + + TP_STRUCT__entry( + __field(u64, link_sid) + __field(size_t, bytes) + ), + TP_fast_assign( + __entry->link_sid = link->stream_id; + __entry->bytes = bytes; + ), + + TP_printk("stream_id=%llu,bytes=%zu", + __entry->link_sid, __entry->bytes) +); + +DECLARE_EVENT_CLASS(tsn_buffer_mgmt_class, + + TP_PROTO(struct tsn_link *link, size_t size), + + TP_ARGS(link, size), + + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(size_t, size) + ), + + TP_fast_assign( + __entry->stream_id = link->stream_id; + __entry->size = size; + ), + + TP_printk("stream_id=%llu,buffer_size=%zu", + __entry->stream_id, __entry->size) + +); + +DEFINE_EVENT(tsn_buffer_mgmt_class, tsn_set_buffer, + TP_PROTO(struct tsn_link *link, size_t size), + TP_ARGS(link, size) +); + +DEFINE_EVENT(tsn_buffer_mgmt_class, tsn_free_buffer, + TP_PROTO(struct tsn_link *link, size_t size), + TP_ARGS(link, size) +); + + +/* TODO: too long, need cleanup. + */ +TRACE_EVENT(tsn_pre_tx, + + TP_PROTO(struct tsn_link *link, struct sk_buff *skb, size_t bytes), + + TP_ARGS(link, skb, bytes), + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(u32, vlan_tag) + __field(size_t, bytes) + __field(size_t, data_len) + __field(unsigned int, headlen) + __field(u16, protocol) + __field(u16, prot_native) + __field(int, tx_idx) + __field(u16, mac_len) + __field(u16, hdr_len) + __field(u16, vlan_tci) + __field(u16, mac_header) + __field(unsigned int, tail) + __field(unsigned int, end) + __field(unsigned int, truesize) + ), + + 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 = vlan_get_protocol(skb); + __entry->prot_native = skb->protocol; + __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, + ntohs(__entry->protocol), + ntohs(__entry->prot_native), + __entry->tx_idx, + __entry->mac_len, + __entry->hdr_len, + __entry->vlan_tci, + __entry->mac_header, + __entry->tail, + __entry->end, + __entry->truesize) + ); + +TRACE_EVENT(tsn_post_tx_set, + + TP_PROTO(struct tsn_link *link, size_t sent), + + TP_ARGS(link, sent), + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(size_t, sent) + ), + + TP_fast_assign( + __entry->stream_id=link->stream_id; + __entry->sent = sent; + ), + + TP_printk("stream_id=%llu,sent=%zu", __entry->stream_id, __entry->sent) + + ); + +TRACE_EVENT(tsn_update_net_time, + + TP_PROTO(struct tsn_link *link), + + TP_ARGS(link), + + TP_STRUCT__entry( + __field(u64, stream_id) + __field(u64, ts_ns) + __field(u64, delta_ns) + __field(u64, delta_avg_ns) + __field(u64, sent_total) + ), + + TP_fast_assign( + __entry->stream_id = link->stream_id; + __entry->ts_ns = link->ts_net_ns; + __entry->delta_ns = link->ts_delta_ns; + __entry->delta_avg_ns = link->ts_exp_avg; + __entry->sent_total = link->frames_sent; + ), + + TP_printk("stream_id=%llu,ts=%llu,ts_delta=%llu,ts_delta_avg=%llu,sent_total=%llu", + __entry->stream_id, + __entry->ts_ns, + __entry->delta_ns, + __entry->delta_avg_ns, + __entry->sent_total) + ); + +#endif /* _TRACE_TSN_H || TRACE_HEADER_MULTI_READ */ + +#include