[PATCH net-next] net: FIB tracepoints

A few useful tracepoints developing VRF driver.

Signed-off-by: David Ahern <redacted>
---
I realize the sensitivity around adding tracepoints, but these have been
invaluable developing the VRF device driver along with a return probe:
  perf probe -a 'fib_table_lookup_ret=fib_table_lookup%return ret=%ax'

 include/trace/events/fib.h | 97 ++++++++++++++++++++++++++++++++++++++++++++++
 net/core/net-traces.c      |  1 +
 net/ipv4/fib_frontend.c    |  3 ++
 net/ipv4/fib_trie.c        |  5 +++
 4 files changed, 106 insertions(+)
 create mode 100644 include/trace/events/fib.h

diff --git a/include/trace/events/fib.h b/include/trace/events/fib.h
new file mode 100644
index 000000000000..1fd7cfeb36ff
--- /dev/null
+++ b/include/trace/events/fib.h

@@ -0,0 +1,97 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM fib
+
+#if !defined(_TRACE_FIB_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_FIB_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <net/ip_fib.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(fib_table_lookup,
+
+	TP_PROTO(int tb_id, const struct flowi4 *flp),
+
+	TP_ARGS(tb_id, flp),
+
+	TP_STRUCT__entry(
+		__field(	int,	tb_id		)
+		__field(	int,	oif		)
+		__field(	int,	iif		)
+		__field(	__u8,	tos		)
+		__field(	__u8,	scope		)
+		__field(	__u8,	flags		)
+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)
+	),
+
+	TP_fast_assign(
+		__entry->tb_id = tb_id;
+		__entry->oif = flp->flowi4_oif;
+		__entry->iif = flp->flowi4_iif;
+		__entry->tos = flp->flowi4_tos;
+		__entry->scope = flp->flowi4_scope;
+		__entry->flags = flp->flowi4_flags;
+		memcpy(&__entry->src,  &flp->saddr, 4);
+		memcpy(&__entry->dst,  &flp->daddr, 4);
+	),
+
+	TP_printk("table %d oif %d iif %d src %pI4 dst %pI4 tos %d scope %d flags %x",
+		  __entry->tb_id, __entry->oif, __entry->iif,
+		  __entry->src, __entry->dst, __entry->tos, __entry->scope,
+		  __entry->flags)
+);
+
+TRACE_EVENT(fib_table_lookup_nh,
+
+	TP_PROTO(const struct fib_nh *nh),
+
+	TP_ARGS(nh),
+
+	TP_STRUCT__entry(
+		__string(	name,	nh->nh_dev->name)
+		__field(	int,	oif		)
+		__array(	__u8,	src,	4	)
+	),
+
+	TP_fast_assign(
+		__assign_str(name, nh->nh_dev ? nh->nh_dev->name : "not set");
+		__entry->oif = nh->nh_oif;
+		memcpy(&__entry->src,  &nh->nh_saddr, 4);
+	),
+
+	TP_printk("nexthop dev %s oif %d src %pI4",
+		  __get_str(name), __entry->oif, __entry->src)
+);
+
+TRACE_EVENT(fib_validate_source,
+
+	TP_PROTO(const struct net_device *dev, const struct flowi4 *flp),
+
+	TP_ARGS(dev, flp),
+
+	TP_STRUCT__entry(
+		__string(	name,	dev->name	)
+		__field(	int,	oif		)
+		__field(	int,	iif		)
+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)
+	),
+
+	TP_fast_assign(
+		__assign_str(name, dev ? dev->name : "not set");
+		__entry->oif = flp->flowi4_oif;
+		__entry->iif = flp->flowi4_iif;
+		memcpy(&__entry->src,  &flp->saddr, 4);
+		memcpy(&__entry->dst,  &flp->daddr, 4);
+	),
+
+	TP_printk("dev %s oif %d iif %d src %pI4 dst %pI4",
+		  __get_str(name), __entry->oif, __entry->iif,
+		  __entry->src, __entry->dst)
+);
+#endif /* _TRACE_FIB_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>

diff --git a/net/core/net-traces.c b/net/core/net-traces.c
index ba3c0120786c..adef015b2f41 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c

@@ -31,6 +31,7 @@
 #include <trace/events/napi.h>
 #include <trace/events/sock.h>
 #include <trace/events/udp.h>
+#include <trace/events/fib.h>
 
 EXPORT_TRACEPOINT_SYMBOL_GPL(kfree_skb);
 

diff --git a/net/ipv4/fib_frontend.c b/net/ipv4/fib_frontend.c
index 7fa277176c33..4036c94dfbe1 100644
--- a/net/ipv4/fib_frontend.c
+++ b/net/ipv4/fib_frontend.c

@@ -46,6 +46,7 @@
 #include <net/rtnetlink.h>
 #include <net/xfrm.h>
 #include <net/vrf.h>
+#include <trace/events/fib.h>
 
 #ifndef CONFIG_IP_MULTIPLE_TABLES
 

@@ -344,6 +345,8 @@ static int __fib_validate_source(struct sk_buff *skb, __be32 src, __be32 dst,
 
 	fl4.flowi4_mark = IN_DEV_SRC_VMARK(idev) ? skb->mark : 0;
 
+	trace_fib_validate_source(dev, &fl4);
+
 	net = dev_net(dev);
 	if (fib_lookup(net, &fl4, &res, 0))
 		goto last_resort;

diff --git a/net/ipv4/fib_trie.c b/net/ipv4/fib_trie.c
index 5154f81c5326..26d6ffb6d23c 100644
--- a/net/ipv4/fib_trie.c
+++ b/net/ipv4/fib_trie.c

@@ -81,6 +81,7 @@
 #include <net/sock.h>
 #include <net/ip_fib.h>
 #include <net/switchdev.h>
+#include <trace/events/fib.h>
 #include "fib_lookup.h"
 
 #define MAX_STAT_DEPTH 32

@@ -1278,6 +1279,8 @@ int fib_table_lookup(struct fib_table *tb, const struct flowi4 *flp,
 	unsigned long index;
 	t_key cindex;
 
+	trace_fib_table_lookup(tb->tb_id, flp);
+
 	pn = t->kv;
 	cindex = 0;
 

@@ -1442,6 +1445,8 @@ int fib_table_lookup(struct fib_table *tb, const struct flowi4 *flp,
 #ifdef CONFIG_IP_FIB_TRIE_STATS
 			this_cpu_inc(stats->semantic_match_passed);
 #endif
+			trace_fib_table_lookup_nh(nh);
+
 			return err;
 		}
 	}

-- 
1.9.1

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 21:59:32 -0700

+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)

 ...

+		__array(	__u8,	src,	4	)

Maybe there is something I don't understand about tracing, but why not
use __u32?  If endianness types are the issue, just force cast it as
needed.

Using a memcpy() on a 4-byte array is kinda excessive.

On 8/27/15 10:05 PM, David Miller wrote:

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 21:59:32 -0700

quoted

+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)

  ...

quoted

+		__array(	__u8,	src,	4	)

Maybe there is something I don't understand about tracing, but why not
use __u32?  If endianness types are the issue, just force cast it as
needed.

Using a memcpy() on a 4-byte array is kinda excessive.

Silly trick need to use %pI4. ie., printing the addresses as strings vs. 
hex.

On 8/27/15 10:07 PM, David Ahern wrote:

On 8/27/15 10:05 PM, David Miller wrote:

quoted

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 21:59:32 -0700

quoted

+        __array(    __u8,    src,    4    )
+        __array(    __u8,    dst,    4    )

  ...

quoted

+        __array(    __u8,    src,    4    )

Maybe there is something I don't understand about tracing, but why not
use __u32?  If endianness types are the issue, just force cast it as
needed.

Using a memcpy() on a 4-byte array is kinda excessive.

Silly trick need to use %pI4. ie., printing the addresses as strings vs.
hex.

perhaps an example helps:

swapper     0 [000]   406.447548: fib:fib_table_lookup: table 255 oif 0 
iif 0 src 0.0.0.0 dst 2.1.1.2 tos 0 scope 0 flags 0

If src and dst are u32's then they print as either 0x%x or %d which is 
not intuitive. I added support to perf for the following printk formats 
with 3d199b5be53:

       %pi4 print an IPv4 address with leading zeros
       %pI4 print an IPv4 address without leading zeros
       %pi6 print an IPv6 address without colons
       %pI6 print an IPv6 address with colons
       %pI6c print an IPv6 address in compressed form with colons
       %pISpc print an IP address from a sockaddr

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:07:30 -0700

On 8/27/15 10:05 PM, David Miller wrote:

quoted

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 21:59:32 -0700

quoted

+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)

  ...

quoted

+		__array(	__u8,	src,	4	)

Maybe there is something I don't understand about tracing, but why not
use __u32?  If endianness types are the issue, just force cast it as
needed.

Using a memcpy() on a 4-byte array is kinda excessive.

Silly trick need to use %pI4. ie., printing the addresses as strings
vs. hex.

%pI4 doesn't care what kind of pointer you give it, &__entry->src will
work just fine if you used __u32.

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:12:01 -0700

perhaps an example helps:

swapper 0 [000] 406.447548: fib:fib_table_lookup: table 255 oif 0 iif
0 src 0.0.0.0 dst 2.1.1.2 tos 0 scope 0 flags 0

If src and dst are u32's then they print as either 0x%x or %d which is
not intuitive. I added support to perf for the following printk
formats with 3d199b5be53:

 ...

The following had better work:

	__u32 addr;
	printk("%pI4\n", &addr);

We do it everywhere in the networking code.

I don't know why you think it is required to use an array.

On 8/27/15 10:16 PM, David Miller wrote:

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:07:30 -0700

quoted

On 8/27/15 10:05 PM, David Miller wrote:

quoted

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 21:59:32 -0700

quoted

+		__array(	__u8,	src,	4	)
+		__array(	__u8,	dst,	4	)

   ...

quoted

+		__array(	__u8,	src,	4	)

Maybe there is something I don't understand about tracing, but why not
use __u32?  If endianness types are the issue, just force cast it as
needed.

Using a memcpy() on a 4-byte array is kinda excessive.

Silly trick need to use %pI4. ie., printing the addresses as strings
vs. hex.

%pI4 doesn't care what kind of pointer you give it, &__entry->src will
work just fine if you used __u32.

$ git diff

diff --git a/include/trace/events/fib.h b/include/trace/events/fib.h
index 1fd7cfeb36ff..07687b93a4f0 100644
--- a/include/trace/events/fib.h
+++ b/include/trace/events/fib.h

@@ -22,7 +22,7 @@ TRACE_EVENT(fib_table_lookup,
                 __field(        __u8,   tos             )
                 __field(        __u8,   scope           )
                 __field(        __u8,   flags           )
-               __array(        __u8,   src,    4       )
+               __field(        __u32,  src     )
                 __array(        __u8,   dst,    4       )
         ),

@@ -33,13 +33,13 @@ TRACE_EVENT(fib_table_lookup,
                 __entry->tos = flp->flowi4_tos;
                 __entry->scope = flp->flowi4_scope;
                 __entry->flags = flp->flowi4_flags;
-               memcpy(&__entry->src,  &flp->saddr, 4);
+               __entry->src = flp->saddr;
                 memcpy(&__entry->dst,  &flp->daddr, 4);
         ),

         TP_printk("table %d oif %d iif %d src %pI4 dst %pI4 tos %d 

scope %d flags %x",
                   __entry->tb_id, __entry->oif, __entry->iif,
-                 __entry->src, __entry->dst, __entry->tos, __entry->scope,
+                 &__entry->src, __entry->dst, __entry->tos, __entry->scope,
                   __entry->flags)
  );

and compiles fine but run time:

$ perf record -e fib:* -a
   Warning: [fib:fib_table_lookup] bad op token &
^C[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.089 MB perf.data (148 samples) ]

$ perf script
  Warning: [fib:fib_table_lookup] bad op token &
...
          swapper     0 [000]    49.533997: fib:fib_table_lookup: 
[FAILED TO PARSE] tb_id=254 oif=0 iif=3 tos=0 scope=0 flags=0 
src=16843096 dst=ARRA
...


ie., it does matter. src was declared a u32 and trying to pass &src to 
the printk fails. Been down this road a lot.

David

On 8/27/15 10:17 PM, David Miller wrote:

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:12:01 -0700

quoted

perhaps an example helps:

swapper 0 [000] 406.447548: fib:fib_table_lookup: table 255 oif 0 iif
0 src 0.0.0.0 dst 2.1.1.2 tos 0 scope 0 flags 0

If src and dst are u32's then they print as either 0x%x or %d which is
not intuitive. I added support to perf for the following printk
formats with 3d199b5be53:

  ...

The following had better work:

	__u32 addr;
	printk("%pI4\n", &addr);

We do it everywhere in the networking code.

I don't know why you think it is required to use an array.

TP_printk is not printk. See my other response.

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:27:38 -0700

ie., it does matter. src was declared a u32 and trying to pass &src to
the printk fails. Been down this road a lot.

It's not printk that's failing, it's the tracing library in userspace
that's being stupid about this.

That's where the "FAILED TO PARSE" thing comes from.

This event parsing code is imposing restrictions that do not exist in
the kernel printk.  And in fact I can't think of a justification for
them, why should this code even care as long as the thing is at least
4 bytes.

From: David Ahern <redacted>
Date: Thu, 27 Aug 2015 22:32:59 -0700

TP_printk is not printk. See my other response.

Then I consider TP_printk to be broken.

Forcing you to memcpy() ipv4 addresses in the "fast assign" of a trace
point is completely stupid.