[PATCH net-next 0/2] tracepoints in neighbor subsystem

[PATCH net-next 0/2] tracepoints in neighbor subsystem

[Roopa Prabhu]

From: Roopa Prabhu <roopa@cumulusnetworks.com>

Roopa Prabhu (2):
  trace: events: add a few neigh tracepoints
  neigh: hook tracepoints in neigh update code

 include/trace/events/neigh.h | 213 +++++++++++++++++++++++++++++++++++++++++++
 net/core/neighbour.c         |  11 +++
 net/core/net-traces.c        |   8 ++
 3 files changed, 232 insertions(+)
 create mode 100644 include/trace/events/neigh.h

-- 
2.1.4

[PATCH net-next 1/2] trace: events: add a few neigh tracepoints

[Roopa Prabhu]

From: Roopa Prabhu <roopa@cumulusnetworks.com>

The goal here is to trace neigh state changes covering all possible
neigh update paths. Plus have a specific trace point in neigh_update
to cover flags sent to neigh_update.

Signed-off-by: Roopa Prabhu <roopa@cumulusnetworks.com>
---
 include/trace/events/neigh.h | 204 +++++++++++++++++++++++++++++++++++++++++++
 net/core/net-traces.c        |   8 ++
 2 files changed, 212 insertions(+)
 create mode 100644 include/trace/events/neigh.h

diff --git a/include/trace/events/neigh.h b/include/trace/events/neigh.h
new file mode 100644
index 0000000..ed10353
--- /dev/null
+++ b/include/trace/events/neigh.h
@@ -0,0 +1,204 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM neigh
+
+#if !defined(_TRACE_NEIGH_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NEIGH_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <linux/tracepoint.h>
+#include <net/neighbour.h>
+
+#define neigh_state_str(state)				\
+	__print_symbolic(state,				\
+		{ NUD_INCOMPLETE, "incomplete" },	\
+		{ NUD_REACHABLE, "reachable" },		\
+		{ NUD_STALE, "stale" },			\
+		{ NUD_DELAY, "delay" },			\
+		{ NUD_PROBE, "probe" },			\
+		{ NUD_FAILED, "failed" })
+
+TRACE_EVENT(neigh_update,
+
+	TP_PROTO(struct neighbour *n, const u8 *lladdr, u8 new,
+		 u32 flags, u32 nlmsg_pid),
+
+	TP_ARGS(n, lladdr, new, flags, nlmsg_pid),
+
+	TP_STRUCT__entry(
+		__field(u32, family)
+		__string(dev, (n->dev ? n->dev->name : "NULL"))
+		__array(u8, lladdr, MAX_ADDR_LEN)
+		__field(u8, lladdr_len)
+		__field(u8, flags)
+		__field(u8, nud_state)
+		__field(u8, type)
+		__field(u8, dead)
+		__field(int, refcnt)
+		__array(__u8, primary_key4, 4)
+		__array(__u8, primary_key6, 16)
+		__field(unsigned long, confirmed)
+		__field(unsigned long, updated)
+		__field(unsigned long, used)
+		__array(u8, new_lladdr, MAX_ADDR_LEN)
+		__field(u8, new_state)
+		__field(u32, update_flags)
+		__field(u32, pid)
+	),
+
+	TP_fast_assign(
+		int lladdr_len = (n->dev ? n->dev->addr_len : MAX_ADDR_LEN);
+		struct in6_addr *pin6;
+		__be32 *p32;
+
+		__entry->family = n->tbl->family;
+		__assign_str(dev, (n->dev ? n->dev->name : "NULL"));
+		__entry->lladdr_len = lladdr_len;
+		memcpy(__entry->lladdr, n->ha, lladdr_len);
+		__entry->flags = n->flags;
+		__entry->nud_state = n->nud_state;
+		__entry->type = n->type;
+		__entry->dead = n->dead;
+		__entry->refcnt = refcount_read(&n->refcnt);
+		pin6 = (struct in6_addr *)__entry->primary_key6;
+		p32 = (__be32 *)__entry->primary_key4;
+
+		if (n->tbl->family == AF_INET)
+			*p32 = *(__be32 *)n->primary_key;
+		else
+			*p32 = 0;
+
+#if IS_ENABLED(CONFIG_IPV6)
+		if (n->tbl->family == AF_INET6) {
+			pin6 = (struct in6_addr *)__entry->primary_key6;
+			*pin6 = *(struct in6_addr *)n->primary_key;
+		} else
+#endif
+		{
+			ipv6_addr_set_v4mapped(*p32, pin6);
+		}
+		__entry->confirmed = n->confirmed;
+		__entry->updated = n->updated;
+		__entry->used = n->used;
+		if (lladdr)
+			memcpy(__entry->new_lladdr, lladdr, lladdr_len);
+		__entry->new_state = new;
+		__entry->update_flags = flags;
+		__entry->pid = nlmsg_pid;
+	),
+
+	TP_printk("family %d dev %s lladdr %s flags %02x nud_state %s type %02x "
+		  "dead %d refcnt %d primary_key4 %pI4 primary_key6 %pI6c "
+		  "confirmed %lu updated %lu used %lu new_lladdr %s "
+		  "new_state %02x update_flags %02x pid %d",
+		  __entry->family, __get_str(dev),
+		  __print_hex_str(__entry->lladdr, __entry->lladdr_len),
+		  __entry->flags, neigh_state_str(__entry->nud_state),
+		  __entry->type, __entry->dead, __entry->refcnt,
+		  __entry->primary_key4, __entry->primary_key6,
+		  __entry->confirmed, __entry->updated, __entry->used,
+		  __print_hex_str(__entry->new_lladdr, __entry->lladdr_len),
+		  __entry->new_state,
+		  __entry->update_flags, __entry->pid)
+);
+
+DECLARE_EVENT_CLASS(neigh__update,
+	TP_PROTO(struct neighbour *n, int err),
+	TP_ARGS(n, err),
+	TP_STRUCT__entry(
+		__field(u32, family)
+		__string(dev, (n->dev ? n->dev->name : "NULL"))
+		__array(u8, lladdr, MAX_ADDR_LEN)
+		__field(u8, lladdr_len)
+		__field(u8, flags)
+		__field(u8, nud_state)
+		__field(u8, type)
+		__field(u8, dead)
+		__field(int, refcnt)
+		__array(__u8, primary_key4, 4)
+		__array(__u8, primary_key6, 16)
+		__field(unsigned long, confirmed)
+		__field(unsigned long, updated)
+		__field(unsigned long, used)
+		__field(u32, err)
+	),
+
+	TP_fast_assign(
+		int lladdr_len = (n->dev ? n->dev->addr_len : MAX_ADDR_LEN);
+		struct in6_addr *pin6;
+		__be32 *p32;
+
+		__entry->family = n->tbl->family;
+		__assign_str(dev, (n->dev ? n->dev->name : "NULL"));
+		__entry->lladdr_len = lladdr_len;
+		memcpy(__entry->lladdr, n->ha, lladdr_len);
+		__entry->flags = n->flags;
+		__entry->nud_state = n->nud_state;
+		__entry->type = n->type;
+		__entry->dead = n->dead;
+		__entry->refcnt = refcount_read(&n->refcnt);
+		pin6 = (struct in6_addr *)__entry->primary_key6;
+		p32 = (__be32 *)__entry->primary_key4;
+
+		if (n->tbl->family == AF_INET)
+			*p32 = *(__be32 *)n->primary_key;
+		else
+			*p32 = 0;
+
+#if IS_ENABLED(CONFIG_IPV6)
+		if (n->tbl->family == AF_INET6) {
+			pin6 = (struct in6_addr *)__entry->primary_key6;
+			*pin6 = *(struct in6_addr *)n->primary_key;
+		} else
+#endif
+		{
+			ipv6_addr_set_v4mapped(*p32, pin6);
+		}
+
+		__entry->confirmed = n->confirmed;
+		__entry->updated = n->updated;
+		__entry->used = n->used;
+		__entry->err = err;
+	),
+
+	TP_printk("family %d dev %s lladdr %s flags %02x nud_state %s type %02x "
+		  "dead %d refcnt %d primary_key4 %pI4 primary_key6 %pI6c "
+		  "confirmed %lu updated %lu used %lu err %d",
+		  __entry->family, __get_str(dev),
+		  __print_hex_str(__entry->lladdr, __entry->lladdr_len),
+		  __entry->flags, neigh_state_str(__entry->nud_state),
+		  __entry->type, __entry->dead, __entry->refcnt,
+		  __entry->primary_key4, __entry->primary_key6,
+		  __entry->confirmed, __entry->updated, __entry->used,
+		  __entry->err)
+);
+
+DEFINE_EVENT(neigh__update, neigh_update_done,
+	TP_PROTO(struct neighbour *neigh, int err),
+	TP_ARGS(neigh, err)
+);
+
+DEFINE_EVENT(neigh__update, neigh_timer_handler,
+	TP_PROTO(struct neighbour *neigh, int err),
+	TP_ARGS(neigh, err)
+);
+
+DEFINE_EVENT(neigh__update, neigh_event_send_done,
+	TP_PROTO(struct neighbour *neigh, int err),
+	TP_ARGS(neigh, err)
+);
+
+DEFINE_EVENT(neigh__update, neigh_event_send_dead,
+	TP_PROTO(struct neighbour *neigh, int err),
+	TP_ARGS(neigh, err)
+);
+
+DEFINE_EVENT(neigh__update, neigh_cleanup_and_release,
+	TP_PROTO(struct neighbour *neigh, int rc),
+	TP_ARGS(neigh, rc)
+);
+
+#endif /* _TRACE_NEIGH_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 419af6d..470b179 100644
--- a/net/core/net-traces.c
+++ b/net/core/net-traces.c
@@ -43,6 +43,14 @@ EXPORT_TRACEPOINT_SYMBOL_GPL(fdb_delete);
 EXPORT_TRACEPOINT_SYMBOL_GPL(br_fdb_update);
 #endif
 
+#include <trace/events/neigh.h>
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_update);
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_update_done);
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_timer_handler);
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_event_send_done);
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_event_send_dead);
+EXPORT_TRACEPOINT_SYMBOL_GPL(neigh_cleanup_and_release);
+
 EXPORT_TRACEPOINT_SYMBOL_GPL(kfree_skb);
 
 EXPORT_TRACEPOINT_SYMBOL_GPL(napi_poll);
-- 
2.1.4

[PATCH net-next 2/2] neigh: hook tracepoints in neigh update code

[Roopa Prabhu]

From: Roopa Prabhu <roopa@cumulusnetworks.com>

hook tracepoints at the end of functions that
update a neigh entry. neigh_update gets an additional
tracepoint to trace the update flags and old and new
neigh states.

Signed-off-by: Roopa Prabhu <roopa@cumulusnetworks.com>
---
 net/core/neighbour.c | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/net/core/neighbour.c b/net/core/neighbour.c
index 4230400..30f6fd8 100644
--- a/net/core/neighbour.c
+++ b/net/core/neighbour.c
@@ -42,6 +42,8 @@
 #include <linux/inetdevice.h>
 #include <net/addrconf.h>
 
+#include <trace/events/neigh.h>
+
 #define DEBUG
 #define NEIGH_DEBUG 1
 #define neigh_dbg(level, fmt, ...)		\
@@ -102,6 +104,7 @@ static void neigh_cleanup_and_release(struct neighbour *neigh)
 	if (neigh->parms->neigh_cleanup)
 		neigh->parms->neigh_cleanup(neigh);
 
+	trace_neigh_cleanup_and_release(neigh, 0);
 	__neigh_notify(neigh, RTM_DELNEIGH, 0, 0);
 	call_netevent_notifiers(NETEVENT_NEIGH_UPDATE, neigh);
 	neigh_release(neigh);
@@ -1095,6 +1098,8 @@ static void neigh_timer_handler(struct timer_list *t)
 	if (notify)
 		neigh_update_notify(neigh, 0);
 
+	trace_neigh_timer_handler(neigh, 0);
+
 	neigh_release(neigh);
 }
 
@@ -1165,6 +1170,7 @@ int __neigh_event_send(struct neighbour *neigh, struct sk_buff *skb)
 	else
 		write_unlock(&neigh->lock);
 	local_bh_enable();
+	trace_neigh_event_send_done(neigh, rc);
 	return rc;
 
 out_dead:
@@ -1172,6 +1178,7 @@ int __neigh_event_send(struct neighbour *neigh, struct sk_buff *skb)
 		goto out_unlock_bh;
 	write_unlock_bh(&neigh->lock);
 	kfree_skb(skb);
+	trace_neigh_event_send_dead(neigh, 1);
 	return 1;
 }
 EXPORT_SYMBOL(__neigh_event_send);
@@ -1227,6 +1234,8 @@ static int __neigh_update(struct neighbour *neigh, const u8 *lladdr,
 	struct net_device *dev;
 	int update_isrouter = 0;
 
+	trace_neigh_update(neigh, lladdr, new, flags, nlmsg_pid);
+
 	write_lock_bh(&neigh->lock);
 
 	dev    = neigh->dev;
@@ -1393,6 +1402,8 @@ static int __neigh_update(struct neighbour *neigh, const u8 *lladdr,
 	if (notify)
 		neigh_update_notify(neigh, nlmsg_pid);
 
+	trace_neigh_update_done(neigh, err);
+
 	return err;
 }
 
-- 
2.1.4

Re: [PATCH net-next 0/2] tracepoints in neighbor subsystem

[David Miller]

From: Roopa Prabhu <roopa@cumulusnetworks.com>
Date: Thu, 14 Feb 2019 09:15:09 -0800

> From: Roopa Prabhu <roopa@cumulusnetworks.com>
> 
> Roopa Prabhu (2):
>   trace: events: add a few neigh tracepoints
>   neigh: hook tracepoints in neigh update code

Series applied, thanks.

Maybe put some actual text in this intro posting next time, explaining
what the series is doing, how it is doing it, and why?

Thanks.

Re: [PATCH net-next 0/2] tracepoints in neighbor subsystem

[Roopa Prabhu]

On Sun, Feb 17, 2019 at 10:34 AM David Miller <davem@davemloft.net> wrote:
>
> From: Roopa Prabhu <roopa@cumulusnetworks.com>
> Date: Thu, 14 Feb 2019 09:15:09 -0800
>
> > From: Roopa Prabhu <roopa@cumulusnetworks.com>
> >
> > Roopa Prabhu (2):
> >   trace: events: add a few neigh tracepoints
> >   neigh: hook tracepoints in neigh update code
>
> Series applied, thanks.
>
> Maybe put some actual text in this intro posting next time, explaining
> what the series is doing, how it is doing it, and why?
>

Oops, My bad. I did have text here in my initial version and possibly
accidentally dropped it when re-generating the cover-letter multiple
times. And absolutely, will keep an eye out to make sure it is
complete next time on. Thanks.


Here are some examples of perf report outputs for neigh creates and
deletes (if anyone wants to review further).
As i type this i realized I missed the converting of new_state to
string. Will send a patch to fix it.

# create a neigh
$ip neigh add 45.0.1.100 dev vlan1001 lladdr 00:02:00:00:00:aa nud reachable

ip  3964 [000] 52484.852372:              neigh:neigh_update: family 2
dev vlan1001 lladdr 000000000000 flags 00 nud_state 0x0 type 01 dead 0
refcnt 2 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4344992162 updated 4347152162 used 4347152162 new_lladdr
0002000000aa new_state 02 update_flags 80000005 pid 3964

ip  3964 [000] 52484.852446:         neigh:neigh_update_done: family 2
dev vlan1001 lladdr 0002000000aa flags 00 nud_state reachable type 01
dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152162 updated 4347152162 used 4347152162 err 0

# change of lladdr on existing neigh
$ip neigh replace 45.0.1.100 dev vlan1001 lladdr 00:02:00:00:00:bb nud reachable

ip  3965 [000] 52484.855838:              neigh:neigh_update: family 2
dev vlan1001 lladdr 0002000000aa flags 00 nud_state reachable type 01
dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152162 updated 4347152162 used 4347152162 new_lladdr
0002000000bb new_state 02 update_flags 80000005 pid 3965

ip  3965 [000] 52484.855883:         neigh:neigh_update_done: family 2
dev vlan1001 lladdr 0002000000bb flags 00 nud_state reachable type 01
dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152165 updated 4347152165 used 4347152162 err 0


# neigh delete, update comes in with NUD_FAILED
$ip neigh del 45.0.1.100 dev vlan1001

ip  3966 [000] 52484.859354:              neigh:neigh_update: family 2
dev vlan1001 lladdr 0002000000bb flags 00 nud_state reachable type 01
dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152165 updated 4347152165 used 4347152162 new_lladdr
00000000766c new_state 20 update_flags 80000001 pid 3966

ip  3966 [000] 52484.859397:         neigh:neigh_update_done: family 2
dev vlan1001 lladdr 0002000000bb flags 00 nud_state failed type 01
dead 0 refcnt 2 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152165 updated 4347152165 used 4347152162 err 0

ip  3966 [000] 52484.859401: neigh:neigh_cleanup_and_release: family 2
dev vlan1001 lladdr 0002000000bb flags 00 nud_state failed type 01
dead 1 refcnt 1 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347152165 updated 4347152165 used 4347152162 err 0


# readd neigh entry and allow it to age, this time
$ip neigh add 45.0.1.100 dev vlan1001 lladdr 00:02:00:00:00:aa nud reachable

ip  4165 [000] 52519.192502:              neigh:neigh_update: family 2
dev vlan1001 lladdr 000000000000 flags 00 nud_state 0x0 type 01 dead 0
refcnt 2 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4345026502 updated 4347186502 used 4347186502 new_lladdr
0002000000aa new_state 02 update_flags 80000005 pid 4165

ip  4165 [000] 52519.192562:         neigh:neigh_update_done: family 2
dev vlan1001 lladdr 0002000000aa flags 00 nud_state reachable type 01
dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347186502 updated 4347186502 used 4347186502 err 0

swapper     0 [000] 53220.306184:       neigh:neigh_timer_handler:
family 2 dev vlan1001 lladdr 0002000000aa flags 00 nud_state reachable
type 01 dead 0 refcnt 3 primary_key4 45.0.1.100 primary_key6
::ffff:45.0.1.100 confirmed 4347186502 updated 4347186502 used
4347186502 err 0

swapper     0 [000] 53973.970238:       neigh:neigh_timer_handler:
family 2 dev vlan1001 lladdr 0002000000aa flags 00 nud_state stale
type 01 dead 0 refcnt 2 primary_key4 45.0.1.100 primary_key6
::ffff:45.0.1.100 confirmed 4347186502 updated 4348641280 used
4347186502 err 0

ip 10268 [000] 65338.084401: neigh:neigh_cleanup_and_release: family 2
dev vlan1001 lladdr 0002000000aa flags 00 nud_state stale type 01 dead
1 refcnt 1 primary_key4 45.0.1.100 primary_key6 ::ffff:45.0.1.100
confirmed 4347186502 updated 4348641280 used 4347186502 err 0