Skip to contentSkip to conversation

netdev: show a process of packets

RFC PATCH Superseded Koki Sanagi 5 participants 26 messages Jun 24, 2010 – Jun 29, 2010

Subsystems (4)
Networking Network drivers perf events Tracing

v2 of 4 Superseded Latest is v4 →

lore
Share & tools
lore

Koki Sanagi

author
#0 lore raw

v2 cover netdev: show a process of packets

CHANGE-LOG since v1:
1) fix to enable "perf trace record netdev-times" run with a script.
2) add some options to "perf trace report netdev-times". A detail is in PATCH 5/5.

These patch-set adds tracepoints to show us a process of packets. Using these tracepoints and existing points, we can get the time when packet passes through some points in transmit or receive sequence. For example, this is an output of perf script which is attached by patch 5/5.

79074.756672832sec cpu=1
irq_entry(+0.000000msec,irq=77:eth3)

         |------------softirq_raise(+0.001277msec)
irq_exit (+0.002278msec)     |
                             |
                      softirq_entry(+0.003562msec)
                             |
                             |---netif_receive_skb(+0.006279msec,len=100)
                             |            |
                             |   skb_copy_datagram_iovec(+0.038778msec, 2285:sshd)
                             |
                      napi_poll_exit(+0.017160msec, eth3)
                             |
                      softirq_exit(+0.018248msec)

The above is a receive side. Like this, it can show receive sequence from interrupt(irq_entry) to application(skb_copy_datagram_iovec). There are 8 tracepoints in this side. All events except for skb_copy_datagram_iovec can be associated with each other by CPU number. skb_copy_datagram_iovec can be associated with netif_receive_skb by skbaddr.
This script shows one NET_RX softirq and events related to it. All relative time bases on first irq_entry which raise NET_RX softirq.

dev len dev_queue_xmit|----------|dev_hard_start_xmit|-----|free_skb

                         |             |                           |
   eth3   114  79044.417123332sec     0.005242msec          0.103843msec
   eth3   114  79044.580090422sec     0.002306msec          0.103632msec
   eth3   114  79044.719078251sec     0.002288msec          0.104093msec

The above is a transmit side. There are three tracepoints in this side. Point1 is before putting a packet to Qdisc. point2 is after ndo_start_xmit in dev_hard_start_xmit. It indicates finishing putting a packet to driver. point3 is in consume_skb and dev_kfree_skb_irq. It indicates freeing a transmitted packet.
Values of this script are, from left, device name, length of a packet, a time of point1, an interval time between point1 and point2 and an interval time between point2 and point3.

These times are useful to analyze a performance or to detect a point where packet delays. For example,
- NET_RX softirq calling is late.
- Application is late to take a packet.
- It takes much time to put a transmitting packet to driver (It may be caused by packed queue)

And also, these tracepoint help us to investigate a network driver's trouble from memory dump because ftrace records it to memory. And ftrace is so light even if always trace on. So, in a case investigating a problem which doesn't reproduce, it is useful.

Thanks,
Koki Sanagi.

author
#1 lore raw

RFC PATCH v2 1/5 irq: add tracepoint to softirq_raise

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/linux/interrupt.h  |    8 +++++++-
 include/trace/events/irq.h |   34 +++++++++++++++++++++++++++++++---
 2 files changed, 38 insertions(+), 4 deletions(-)
include/linux/interrupt.h +7 -1
index c233113..1cb5726 100644
@@ -18,6 +18,7 @@
 #include <asm/atomic.h>
 #include <asm/ptrace.h>
 #include <asm/system.h>
+#include <trace/events/irq.h>
 
 /*
  * These correspond to the IORESOURCE_IRQ_* defines in

@@ -402,7 +403,12 @@ asmlinkage void do_softirq(void);
 asmlinkage void __do_softirq(void);
 extern void open_softirq(int nr, void (*action)(struct softirq_action *));
 extern void softirq_init(void);
-#define __raise_softirq_irqoff(nr) do { or_softirq_pending(1UL << (nr)); } while (0)
+static inline void __raise_softirq_irqoff(unsigned int nr)
+{
+	trace_softirq_raise(nr);
+	or_softirq_pending(1UL << nr);
+}
+
 extern void raise_softirq_irqoff(unsigned int nr);
 extern void raise_softirq(unsigned int nr);
 extern void wakeup_softirqd(void);
include/trace/events/irq.h +31 -3
index 0e4cfb6..7cb7435 100644
@@ -5,7 +5,9 @@
 #define _TRACE_IRQ_H
 
 #include <linux/tracepoint.h>
-#include <linux/interrupt.h>
+
+struct irqaction;
+struct softirq_action;
 
 #define softirq_name(sirq) { sirq##_SOFTIRQ, #sirq }
 #define show_softirq_name(val)				\

@@ -82,6 +84,32 @@ TRACE_EVENT(irq_handler_exit,
 		  __entry->irq, __entry->ret ? "handled" : "unhandled")
 );
 
+/**
+ * softirq_raise - called immediately when a softirq is raised
+ * @nr: softirq vector number
+ *
+ * Tracepoint for tracing when softirq action is raised.
+ * Also, when used in combination with the softirq_entry tracepoint
+ * we can determine the softirq raise latency.
+ */
+TRACE_EVENT(softirq_raise,
+
+	TP_PROTO(unsigned int nr),
+
+	TP_ARGS(nr),
+
+	TP_STRUCT__entry(
+		__field(	unsigned int,	vec	)
+	),
+
+	TP_fast_assign(
+		__entry->vec	= nr;
+	),
+
+	TP_printk("vec=%d [action=%s]", __entry->vec,
+		show_softirq_name(__entry->vec))
+);
+
 DECLARE_EVENT_CLASS(softirq,
 
 	TP_PROTO(struct softirq_action *h, struct softirq_action *vec),

@@ -89,11 +117,11 @@ DECLARE_EVENT_CLASS(softirq,
 	TP_ARGS(h, vec),
 
 	TP_STRUCT__entry(
-		__field(	int,	vec			)
+		__field(	unsigned int,	vec	)
 	),
 
 	TP_fast_assign(
-		__entry->vec = (int)(h - vec);
+		__entry->vec = (unsigned int)(h - vec);
 	),
 
 	TP_printk("vec=%d [action=%s]", __entry->vec,
maintainer
#2 lore raw

Re: [RFC PATCH v2 1/5] irq: add tracepoint to softirq_raise

Hi Koki,

Your subject says 1/5 but I do not see any other patches.

Quoted 78 lines · Koki Sanagi

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/linux/interrupt.h  |    8 +++++++-
 include/trace/events/irq.h |   34 +++++++++++++++++++++++++++++++---
 2 files changed, 38 insertions(+), 4 deletions(-)
include/linux/interrupt.h +7 -1
index c233113..1cb5726 100644
@@ -18,6 +18,7 @@
 #include <asm/atomic.h>
 #include <asm/ptrace.h>
 #include <asm/system.h>
+#include <trace/events/irq.h>
 
 /*
  * These correspond to the IORESOURCE_IRQ_* defines in

@@ -402,7 +403,12 @@ asmlinkage void do_softirq(void);
 asmlinkage void __do_softirq(void);
 extern void open_softirq(int nr, void (*action)(struct softirq_action *));
 extern void softirq_init(void);
-#define __raise_softirq_irqoff(nr) do { or_softirq_pending(1UL << (nr)); } while (0)
+static inline void __raise_softirq_irqoff(unsigned int nr)
+{
+	trace_softirq_raise(nr);
+	or_softirq_pending(1UL << nr);
+}
+
 extern void raise_softirq_irqoff(unsigned int nr);
 extern void raise_softirq(unsigned int nr);
 extern void wakeup_softirqd(void);
include/trace/events/irq.h +17 -1
index 0e4cfb6..7cb7435 100644
@@ -5,7 +5,9 @@
 #define _TRACE_IRQ_H
 
 #include <linux/tracepoint.h>
-#include <linux/interrupt.h>
+
+struct irqaction;
+struct softirq_action;
 
 #define softirq_name(sirq) { sirq##_SOFTIRQ, #sirq }
 #define show_softirq_name(val)				\

@@ -82,6 +84,32 @@ TRACE_EVENT(irq_handler_exit,
 		  __entry->irq, __entry->ret ? "handled" : "unhandled")
 );
 
+/**
+ * softirq_raise - called immediately when a softirq is raised
+ * @nr: softirq vector number
+ *
+ * Tracepoint for tracing when softirq action is raised.
+ * Also, when used in combination with the softirq_entry tracepoint
+ * we can determine the softirq raise latency.
+ */
+TRACE_EVENT(softirq_raise,
+
+	TP_PROTO(unsigned int nr),
+
+	TP_ARGS(nr),
+

include/trace/events/irq.h TRACE_EVENT(irq_handler_exit, · line 110

Quoted 10 lines
include/trace/events/irq.h +10 -0
+	TP_STRUCT__entry(
+		__field(	unsigned int,	vec	)
+	),
+
+	TP_fast_assign(
+		__entry->vec	= nr;
+	),
+
+	TP_printk("vec=%d [action=%s]", __entry->vec,
+		show_softirq_name(__entry->vec))

Hmm, is there a way to reuse a DECLARE_EVENT_CLASS here?

Quoted 6 lines
include/trace/events/irq.h +2 -0
+);
+
 DECLARE_EVENT_CLASS(softirq,
 
 	TP_PROTO(struct softirq_action *h, struct softirq_action *vec),

include/trace/events/irq.h DECLARE_EVENT_CLASS(softirq, · line 124

Quoted 10 lines
include/trace/events/irq.h +2 -2
@@ -89,11 +117,11 @@ DECLARE_EVENT_CLASS(softirq,
 	TP_ARGS(h, vec),
 
 	TP_STRUCT__entry(
-		__field(	int,	vec			)
+		__field(	unsigned int,	vec	)
 	),
 
 	TP_fast_assign(
-		__entry->vec = (int)(h - vec);
+		__entry->vec = (unsigned int)(h - vec);

Just curious, did you see the original as a bug?

-- Steve

Quoted 3 lines
include/trace/events/irq.h +0 -0
 	),
 
 	TP_printk("vec=%d [action=%s]", __entry->vec,
author
#3 lore raw

Re: [RFC PATCH v2 1/5] irq: add tracepoint to softirq_raise

Hi Steven,

Sorry, I submitted other patches to only netdev.
I'll resubmit soon all patches to linux-kernel.

Quoted 129 lines · Steven Rostedt

Hi Koki,

Your subject says 1/5 but I do not see any other patches.

Quoted 78 lines · Koki Sanagi

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/linux/interrupt.h  |    8 +++++++-
 include/trace/events/irq.h |   34 +++++++++++++++++++++++++++++++---
 2 files changed, 38 insertions(+), 4 deletions(-)
include/linux/interrupt.h +7 -1
index c233113..1cb5726 100644
@@ -18,6 +18,7 @@
 #include <asm/atomic.h>
 #include <asm/ptrace.h>
 #include <asm/system.h>
+#include <trace/events/irq.h>
 
 /*
  * These correspond to the IORESOURCE_IRQ_* defines in

@@ -402,7 +403,12 @@ asmlinkage void do_softirq(void);
 asmlinkage void __do_softirq(void);
 extern void open_softirq(int nr, void (*action)(struct softirq_action *));
 extern void softirq_init(void);
-#define __raise_softirq_irqoff(nr) do { or_softirq_pending(1UL << (nr)); } while (0)
+static inline void __raise_softirq_irqoff(unsigned int nr)
+{
+	trace_softirq_raise(nr);
+	or_softirq_pending(1UL << nr);
+}
+
 extern void raise_softirq_irqoff(unsigned int nr);
 extern void raise_softirq(unsigned int nr);
 extern void wakeup_softirqd(void);
include/trace/events/irq.h +17 -1
index 0e4cfb6..7cb7435 100644
@@ -5,7 +5,9 @@
 #define _TRACE_IRQ_H
 
 #include <linux/tracepoint.h>
-#include <linux/interrupt.h>
+
+struct irqaction;
+struct softirq_action;
 
 #define softirq_name(sirq) { sirq##_SOFTIRQ, #sirq }
 #define show_softirq_name(val)				\

@@ -82,6 +84,32 @@ TRACE_EVENT(irq_handler_exit,
 		  __entry->irq, __entry->ret ? "handled" : "unhandled")
 );
 
+/**
+ * softirq_raise - called immediately when a softirq is raised
+ * @nr: softirq vector number
+ *
+ * Tracepoint for tracing when softirq action is raised.
+ * Also, when used in combination with the softirq_entry tracepoint
+ * we can determine the softirq raise latency.
+ */
+TRACE_EVENT(softirq_raise,
+
+	TP_PROTO(unsigned int nr),
+
+	TP_ARGS(nr),
+

include/trace/events/irq.h TRACE_EVENT(irq_handler_exit, · line 110

Quoted 10 lines
include/trace/events/irq.h +10 -0
+	TP_STRUCT__entry(
+		__field(	unsigned int,	vec	)
+	),
+
+	TP_fast_assign(
+		__entry->vec	= nr;
+	),
+
+	TP_printk("vec=%d [action=%s]", __entry->vec,
+		show_softirq_name(__entry->vec))

Hmm, is there a way to reuse a DECLARE_EVENT_CLASS here?

Quoted 6 lines
include/trace/events/irq.h +2 -0
+);
+
 DECLARE_EVENT_CLASS(softirq,
 
 	TP_PROTO(struct softirq_action *h, struct softirq_action *vec),

include/trace/events/irq.h DECLARE_EVENT_CLASS(softirq, · line 124

Quoted 10 lines
include/trace/events/irq.h +2 -2
@@ -89,11 +117,11 @@ DECLARE_EVENT_CLASS(softirq,
 	TP_ARGS(h, vec),
 
 	TP_STRUCT__entry(
-		__field(	int,	vec			)
+		__field(	unsigned int,	vec	)
 	),
 
 	TP_fast_assign(
-		__entry->vec = (int)(h - vec);
+		__entry->vec = (unsigned int)(h - vec);

Just curious, did you see the original as a bug?

-- Steve

include/trace/events/irq.h DECLARE_EVENT_CLASS(softirq, · line 127

Quoted 3 lines
include/trace/events/irq.h +0 -0
 	),
 
 	TP_printk("vec=%d [action=%s]", __entry->vec,

--
To unsubscribe from this list: send the line "unsubscribe netdev" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

author
#4 lore raw

RFC PATCH v2 1/5 irq: add tracepoint to softirq_raise

In reply to Koki Sanagi

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/linux/interrupt.h  |    8 +++++++-
 include/trace/events/irq.h |   34 +++++++++++++++++++++++++++++++---
 2 files changed, 38 insertions(+), 4 deletions(-)
include/linux/interrupt.h +7 -1
index c233113..1cb5726 100644
@@ -18,6 +18,7 @@
 #include <asm/atomic.h>
 #include <asm/ptrace.h>
 #include <asm/system.h>
+#include <trace/events/irq.h>
 
 /*
  * These correspond to the IORESOURCE_IRQ_* defines in

@@ -402,7 +403,12 @@ asmlinkage void do_softirq(void);
 asmlinkage void __do_softirq(void);
 extern void open_softirq(int nr, void (*action)(struct softirq_action *));
 extern void softirq_init(void);
-#define __raise_softirq_irqoff(nr) do { or_softirq_pending(1UL << (nr)); } while (0)
+static inline void __raise_softirq_irqoff(unsigned int nr)
+{
+	trace_softirq_raise(nr);
+	or_softirq_pending(1UL << nr);
+}
+
 extern void raise_softirq_irqoff(unsigned int nr);
 extern void raise_softirq(unsigned int nr);
 extern void wakeup_softirqd(void);
include/trace/events/irq.h +31 -3
index 0e4cfb6..7cb7435 100644
@@ -5,7 +5,9 @@
 #define _TRACE_IRQ_H
 
 #include <linux/tracepoint.h>
-#include <linux/interrupt.h>
+
+struct irqaction;
+struct softirq_action;
 
 #define softirq_name(sirq) { sirq##_SOFTIRQ, #sirq }
 #define show_softirq_name(val)				\

@@ -82,6 +84,32 @@ TRACE_EVENT(irq_handler_exit,
 		  __entry->irq, __entry->ret ? "handled" : "unhandled")
 );
 
+/**
+ * softirq_raise - called immediately when a softirq is raised
+ * @nr: softirq vector number
+ *
+ * Tracepoint for tracing when softirq action is raised.
+ * Also, when used in combination with the softirq_entry tracepoint
+ * we can determine the softirq raise latency.
+ */
+TRACE_EVENT(softirq_raise,
+
+	TP_PROTO(unsigned int nr),
+
+	TP_ARGS(nr),
+
+	TP_STRUCT__entry(
+		__field(	unsigned int,	vec	)
+	),
+
+	TP_fast_assign(
+		__entry->vec	= nr;
+	),
+
+	TP_printk("vec=%d [action=%s]", __entry->vec,
+		show_softirq_name(__entry->vec))
+);
+
 DECLARE_EVENT_CLASS(softirq,
 
 	TP_PROTO(struct softirq_action *h, struct softirq_action *vec),

@@ -89,11 +117,11 @@ DECLARE_EVENT_CLASS(softirq,
 	TP_ARGS(h, vec),
 
 	TP_STRUCT__entry(
-		__field(	int,	vec			)
+		__field(	unsigned int,	vec	)
 	),
 
 	TP_fast_assign(
-		__entry->vec = (int)(h - vec);
+		__entry->vec = (unsigned int)(h - vec);
 	),
 
 	TP_printk("vec=%d [action=%s]", __entry->vec,
Acked-by Mathieu Desnoyers Acked-by Frederic Weisbecker on v2 1/5
#5 lore raw

Re: [RFC PATCH v2 1/5] irq: add tracepoint to softirq_raise

(cc to Lai)

Quoted 6 lines

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

Quoted 6 lines
          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

If so, you shouldn't remove author's info. please fix the description as following.

-------------------------------------------------------------------------
From: Lai Jiangshan <[email protected]>

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same below.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Lai Jiangshan <[email protected]>
Acked-by Mathieu Desnoyers <[email protected]>
Acked-by Frederic Weisbecker <[email protected]>
Signed-off-by Koki Sanagi <[email protected]>

--------------------------------------------------------------------------------

author
#6 lore raw

Re: [RFC PATCH v2 1/5] irq: add tracepoint to softirq_raise

Thanks Kosaki,

I'll fix a description.

Quoted 43 lines · KOSAKI Motohiro

(cc to Lai)

Quoted 6 lines

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

Quoted 6 lines
          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

If so, you shouldn't remove author's info. please fix the description as following.

-------------------------------------------------------------------------
From: Lai Jiangshan <[email protected]>

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX]
          <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER]
          <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same below.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Lai Jiangshan <[email protected]>
Acked-by Mathieu Desnoyers <[email protected]>
Acked-by Frederic Weisbecker <[email protected]>
Signed-off-by Koki Sanagi <[email protected]>

--------------------------------------------------------------------------------

#7 lore raw

Re: [RFC PATCH v2 1/5] irq: add tracepoint to softirq_raise

In reply to KOSAKI Motohiro

2010/6/25 KOSAKI Motohiro <[email protected]>:

Quoted 31 lines

(cc to Lai)

Quoted 6 lines

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

Quoted 6 lines

          <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX] <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER] <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

This is a same patch Lai Jiangshan submitted.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

If so, you shouldn't remove author's info. please fix the description as following.

-------------------------------------------------------------------------
From: Lai Jiangshan <[email protected]>

This patch adds a tracepoint to raising of softirq.
This is useful if you want to detect which hard interrupt raise softirq and lets you know a time between raising softirq and performing softirq. Combinating with other tracepoint, it lets us know a process of packets (See patch 0/5).

         <idle>-0     [001] 241229.957184: softirq_raise: vec=3 [action=NET_RX] <idle>-0     [000] 241229.993399: softirq_raise: vec=1 [action=TIMER] <idle>-0     [000] 241229.993400: softirq_raise: vec=9 [action=RCU]

Quoted 6 lines

This is a same below.
http://marc.info/?l=linux-kernel&m=126026122728732&w=2

Signed-off-by Lai Jiangshan <[email protected]>
Acked-by Mathieu Desnoyers <[email protected]>
Acked-by Frederic Weisbecker <[email protected]>

Right. And if you do some changes in the original patch, you can just change the description, or add a simple line before your Signed-off-by, that says:

[ factorize softirq events with DECLARE_EVENT_CLASS ]

Because indeed, as Steve said, the softirq_raise tracepoint should belong to the softirq event class as it perfectly matches it. This helps the kernel
saving some space.

Thanks.

Quoted 10 lines
Signed-off-by Koki Sanagi <[email protected]>

--------------------------------------------------------------------------------

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

author
#8 lore raw

RFC PATCH v2 2/5 napi: convert trace_napi_poll to TRACE_EVENT

In reply to Koki Sanagi

This patch converts trace_napi_poll from DECLARE_EVENT to TRACE_EVENT. This lets you know how long napi_poll takes.

          <idle>-0     [001] 241302.750777: napi_poll: napi poll on napi struct f6acc480 for device eth3
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d70c for device eth1
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d20c for device eth1

This is a same patch Neil Horman submitted.
http://marc.info/?l=linux-kernel&m=125978157926853&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/napi.h |   23 +++++++++++++++++++++--
 1 files changed, 21 insertions(+), 2 deletions(-)
include/trace/events/napi.h +21 -2
index 188deca..512a057 100644
@@ -6,10 +6,29 @@
 
 #include <linux/netdevice.h>
 #include <linux/tracepoint.h>
+#include <linux/ftrace.h>
+
+#define NO_DEV "(no_device)"
+
+TRACE_EVENT(napi_poll,
 
-DECLARE_TRACE(napi_poll,
 	TP_PROTO(struct napi_struct *napi),
-	TP_ARGS(napi));
+
+	TP_ARGS(napi),
+
+	TP_STRUCT__entry(
+		__field(	struct napi_struct *,	napi)
+		__string(	dev_name, napi->dev ? napi->dev->name : NO_DEV)
+	),
+
+	TP_fast_assign(
+		__entry->napi = napi;
+		__assign_str(dev_name, napi->dev ? napi->dev->name : NO_DEV);
+	),
+
+	TP_printk("napi poll on napi struct %p for device %s",
+		__entry->napi, __get_str(dev_name))
+);
 
 #endif /* _TRACE_NAPI_H_ */
author
#9 lore raw

RFC PATCH v2 2/5 napi: convert trace_napi_poll to TRACE_EVENT

In reply to Koki Sanagi

This patch converts trace_napi_poll from DECLARE_EVENT to TRACE_EVENT. This lets you know how long napi_poll takes.

          <idle>-0     [001] 241302.750777: napi_poll: napi poll on napi struct f6acc480 for device eth3
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d70c for device eth1
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d20c for device eth1

This is a same patch Neil Horman submitted.
http://marc.info/?l=linux-kernel&m=125978157926853&w=2

Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/napi.h |   23 +++++++++++++++++++++--
 1 files changed, 21 insertions(+), 2 deletions(-)
include/trace/events/napi.h +21 -2
index 188deca..512a057 100644
@@ -6,10 +6,29 @@
 
 #include <linux/netdevice.h>
 #include <linux/tracepoint.h>
+#include <linux/ftrace.h>
+
+#define NO_DEV "(no_device)"
+
+TRACE_EVENT(napi_poll,
 
-DECLARE_TRACE(napi_poll,
 	TP_PROTO(struct napi_struct *napi),
-	TP_ARGS(napi));
+
+	TP_ARGS(napi),
+
+	TP_STRUCT__entry(
+		__field(	struct napi_struct *,	napi)
+		__string(	dev_name, napi->dev ? napi->dev->name : NO_DEV)
+	),
+
+	TP_fast_assign(
+		__entry->napi = napi;
+		__assign_str(dev_name, napi->dev ? napi->dev->name : NO_DEV);
+	),
+
+	TP_printk("napi poll on napi struct %p for device %s",
+		__entry->napi, __get_str(dev_name))
+);
 
 #endif /* _TRACE_NAPI_H_ */
#10 lore raw

Re: [RFC PATCH v2 2/5] napi: convert trace_napi_poll to TRACE_EVENT

Quoted 9 lines

This patch converts trace_napi_poll from DECLARE_EVENT to TRACE_EVENT. This lets you know how long napi_poll takes.

          <idle>-0     [001] 241302.750777: napi_poll: napi poll on napi struct f6acc480 for device eth3
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d70c for device eth1
          <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d20c for device eth1

This is a same patch Neil Horman submitted.
http://marc.info/?l=linux-kernel&m=125978157926853&w=2

Ditto.
Please don't remove Neil's S-O-B.

#11 lore raw

Re: [RFC PATCH v2 2/5] napi: convert trace_napi_poll to TRACE_EVENT

In reply to Koki Sanagi

2010/6/25 Koki Sanagi <[email protected]>:

Quoted 4 lines

This patch converts trace_napi_poll from DECLARE_EVENT to TRACE_EVENT.

From DECLARE_TRACE to TRACE_EVENT.

Or more generally: this expands the napi polling tracepoint to a trace event, to improve the
napi polling tracepoint usability.

Quoted 8 lines

This lets you know how long napi_poll takes.

         <idle>-0     [001] 241302.750777: napi_poll: napi poll on napi struct f6acc480 for device eth3 <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d70c for device eth1 <idle>-0     [000] 241302.852389: napi_poll: napi poll on napi struct f5d0d20c for device eth1

This is a same patch Neil Horman submitted.
http://marc.info/?l=linux-kernel&m=125978157926853&w=2

Hmm, nope, doesn't seem to be the same patch.

author
#12 lore raw

RFC PATCH v2 3/5 netdev: add tracepoints to netdev layer

In reply to Koki Sanagi

This patch adds tracepoint to dev_queue_xmit, dev_hard_start_xmit and netif_receive_skb. These tracepints help you to monitor network driver's input/output.

            sshd-4445  [001] 241367.066046: net_dev_queue: dev=eth3 skbaddr=dd6b2538 len=114
            sshd-4445  [001] 241367.066047: net_dev_xmit: dev=eth3 skbaddr=dd6b2538 len=114 rc=0
          <idle>-0     [001] 241367.067472: net_dev_receive: dev=eth3 skbaddr=f5e59000 len=52
Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/net.h |   83 ++++++++++++++++++++++++++++++++++++++++++++
 net/core/dev.c             |    5 +++
 net/core/net-traces.c      |    1 +
 3 files changed, 89 insertions(+), 0 deletions(-)
include/trace/events/net.h new file +83 -0
new file mode 100644
index 0000000..ee10970
@@ -0,0 +1,83 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM net
+
+#if !defined(_TRACE_NET_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NET_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <linux/ip.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(net_dev_xmit,
+
+	TP_PROTO(struct sk_buff *skb,
+		 int rc),
+
+	TP_ARGS(skb, rc),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__field(	int,		rc		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__entry->rc = rc;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u rc=%d",
+		__get_str(name), __entry->skbaddr, __entry->len, __entry->rc)
+);
+
+TRACE_EVENT(net_dev_queue,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+
+TRACE_EVENT(net_dev_receive,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+#endif /* _TRACE_NET_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
net/core/dev.c +5 -0
index 5902426..4b64b21 100644
@@ -130,6 +130,7 @@
 #include <linux/jhash.h>
 #include <linux/random.h>
 #include <trace/events/napi.h>
+#include <trace/events/net.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1922,6 +1923,7 @@ int dev_hard_start_xmit(struct sk_buff *skb, struct net_device *dev,
 		}
 
 		rc = ops->ndo_start_xmit(skb, dev);
+		trace_net_dev_xmit(skb, rc);
 		if (rc == NETDEV_TX_OK)
 			txq_trans_update(txq);
 		return rc;

@@ -1942,6 +1944,7 @@ gso:
 			skb_dst_drop(nskb);
 
 		rc = ops->ndo_start_xmit(nskb, dev);
+		trace_net_dev_xmit(nskb, rc);
 		if (unlikely(rc != NETDEV_TX_OK)) {
 			if (rc & ~NETDEV_TX_MASK)
 				goto out_kfree_gso_skb;

@@ -2156,6 +2159,7 @@ int dev_queue_xmit(struct sk_buff *skb)
 	}
 
 gso:
+	trace_net_dev_queue(skb);
 	/* Disable soft irqs for various locks below. Also
 	 * stops preemption for RCU.
 	 */

@@ -2942,6 +2946,7 @@ int netif_receive_skb(struct sk_buff *skb)
 	if (netdev_tstamp_prequeue)
 		net_timestamp_check(skb);
 
+	trace_net_dev_receive(skb);
 #ifdef CONFIG_RPS
 	{
 		struct rps_dev_flow voidflow, *rflow = &voidflow;
net/core/net-traces.c +1 -0
index afa6380..7f1bb2a 100644
@@ -26,6 +26,7 @@
 
 #define CREATE_TRACE_POINTS
 #include <trace/events/skb.h>
+#include <trace/events/net.h>
 #include <trace/events/napi.h>
 
 EXPORT_TRACEPOINT_SYMBOL_GPL(kfree_skb);
author
#13 lore raw

RFC PATCH v2 3/5 netdev: add tracepoints to netdev layer

In reply to Koki Sanagi

This patch adds tracepoint to dev_queue_xmit, dev_hard_start_xmit and netif_receive_skb. These tracepints help you to monitor network driver's input/output.

            sshd-4445  [001] 241367.066046: net_dev_queue: dev=eth3 skbaddr=dd6b2538 len=114
            sshd-4445  [001] 241367.066047: net_dev_xmit: dev=eth3 skbaddr=dd6b2538 len=114 rc=0
          <idle>-0     [001] 241367.067472: net_dev_receive: dev=eth3 skbaddr=f5e59000 len=52
Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/net.h |   83 ++++++++++++++++++++++++++++++++++++++++++++
 net/core/dev.c             |    5 +++
 net/core/net-traces.c      |    1 +
 3 files changed, 89 insertions(+), 0 deletions(-)
include/trace/events/net.h new file +83 -0
new file mode 100644
index 0000000..ee10970
@@ -0,0 +1,83 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM net
+
+#if !defined(_TRACE_NET_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NET_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <linux/ip.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(net_dev_xmit,
+
+	TP_PROTO(struct sk_buff *skb,
+		 int rc),
+
+	TP_ARGS(skb, rc),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__field(	int,		rc		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__entry->rc = rc;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u rc=%d",
+		__get_str(name), __entry->skbaddr, __entry->len, __entry->rc)
+);
+
+TRACE_EVENT(net_dev_queue,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+
+TRACE_EVENT(net_dev_receive,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+#endif /* _TRACE_NET_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
net/core/dev.c +5 -0
index 5902426..4b64b21 100644
@@ -130,6 +130,7 @@
 #include <linux/jhash.h>
 #include <linux/random.h>
 #include <trace/events/napi.h>
+#include <trace/events/net.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1922,6 +1923,7 @@ int dev_hard_start_xmit(struct sk_buff *skb, struct net_device *dev,
 		}
 
 		rc = ops->ndo_start_xmit(skb, dev);
+		trace_net_dev_xmit(skb, rc);
 		if (rc == NETDEV_TX_OK)
 			txq_trans_update(txq);
 		return rc;

@@ -1942,6 +1944,7 @@ gso:
 			skb_dst_drop(nskb);
 
 		rc = ops->ndo_start_xmit(nskb, dev);
+		trace_net_dev_xmit(nskb, rc);
 		if (unlikely(rc != NETDEV_TX_OK)) {
 			if (rc & ~NETDEV_TX_MASK)
 				goto out_kfree_gso_skb;

@@ -2156,6 +2159,7 @@ int dev_queue_xmit(struct sk_buff *skb)
 	}
 
 gso:
+	trace_net_dev_queue(skb);
 	/* Disable soft irqs for various locks below. Also
 	 * stops preemption for RCU.
 	 */

@@ -2942,6 +2946,7 @@ int netif_receive_skb(struct sk_buff *skb)
 	if (netdev_tstamp_prequeue)
 		net_timestamp_check(skb);
 
+	trace_net_dev_receive(skb);
 #ifdef CONFIG_RPS
 	{
 		struct rps_dev_flow voidflow, *rflow = &voidflow;
net/core/net-traces.c +1 -0
index afa6380..7f1bb2a 100644
@@ -26,6 +26,7 @@
 
 #define CREATE_TRACE_POINTS
 #include <trace/events/skb.h>
+#include <trace/events/net.h>
 #include <trace/events/napi.h>
 
 EXPORT_TRACEPOINT_SYMBOL_GPL(kfree_skb);
maintainer
#14 lore raw

Re: [RFC PATCH v2 3/5] netdev: add tracepoints to netdev layer

Quoted 70 lines · Koki Sanagi

This patch adds tracepoint to dev_queue_xmit, dev_hard_start_xmit and netif_receive_skb. These tracepints help you to monitor network driver's input/output.

            sshd-4445  [001] 241367.066046: net_dev_queue: dev=eth3 skbaddr=dd6b2538 len=114
            sshd-4445  [001] 241367.066047: net_dev_xmit: dev=eth3 skbaddr=dd6b2538 len=114 rc=0
          <idle>-0     [001] 241367.067472: net_dev_receive: dev=eth3 skbaddr=f5e59000 len=52
Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/net.h |   83 ++++++++++++++++++++++++++++++++++++++++++++
 net/core/dev.c             |    5 +++
 net/core/net-traces.c      |    1 +
 3 files changed, 89 insertions(+), 0 deletions(-)
include/trace/events/net.h new file +49 -0
new file mode 100644
index 0000000..ee10970
@@ -0,0 +1,83 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM net
+
+#if !defined(_TRACE_NET_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NET_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <linux/ip.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(net_dev_xmit,
+
+	TP_PROTO(struct sk_buff *skb,
+		 int rc),
+
+	TP_ARGS(skb, rc),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__field(	int,		rc		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__entry->rc = rc;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u rc=%d",
+		__get_str(name), __entry->skbaddr, __entry->len, __entry->rc)
+);
+
+TRACE_EVENT(net_dev_queue,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(

include/trace/events/net.h line 59

Quoted 10 lines
include/trace/events/net.h new file +10 -0
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+
+TRACE_EVENT(net_dev_receive,

This and net_dev_queue are identical. Please use DECLARE_EVENT_CLASS() and DEFINE_EVENT() to create these, otherwise it bloats the kernel.

-- Steve

Quoted 22 lines
include/trace/events/net.h new file +22 -0
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+#endif /* _TRACE_NET_H */
+
author
#15 lore raw

Re: [RFC PATCH v2 3/5] netdev: add tracepoints to netdev layer

Quoted 85 lines · Steven Rostedt
Quoted 70 lines · Koki Sanagi

This patch adds tracepoint to dev_queue_xmit, dev_hard_start_xmit and netif_receive_skb. These tracepints help you to monitor network driver's input/output.

            sshd-4445  [001] 241367.066046: net_dev_queue: dev=eth3 skbaddr=dd6b2538 len=114
            sshd-4445  [001] 241367.066047: net_dev_xmit: dev=eth3 skbaddr=dd6b2538 len=114 rc=0
          <idle>-0     [001] 241367.067472: net_dev_receive: dev=eth3 skbaddr=f5e59000 len=52
Signed-off-by Koki Sanagi <[email protected]>
---
 include/trace/events/net.h |   83 ++++++++++++++++++++++++++++++++++++++++++++
 net/core/dev.c             |    5 +++
 net/core/net-traces.c      |    1 +
 3 files changed, 89 insertions(+), 0 deletions(-)
include/trace/events/net.h new file +49 -0
new file mode 100644
index 0000000..ee10970
@@ -0,0 +1,83 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM net
+
+#if !defined(_TRACE_NET_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_NET_H
+
+#include <linux/skbuff.h>
+#include <linux/netdevice.h>
+#include <linux/ip.h>
+#include <linux/tracepoint.h>
+
+TRACE_EVENT(net_dev_xmit,
+
+	TP_PROTO(struct sk_buff *skb,
+		 int rc),
+
+	TP_ARGS(skb, rc),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__field(	int,		rc		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__entry->rc = rc;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u rc=%d",
+		__get_str(name), __entry->skbaddr, __entry->len, __entry->rc)
+);
+
+TRACE_EVENT(net_dev_queue,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(

include/trace/events/net.h line 59

Quoted 10 lines
include/trace/events/net.h new file +10 -0
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+
+TRACE_EVENT(net_dev_receive,

This and net_dev_queue are identical. Please use DECLARE_EVENT_CLASS() and DEFINE_EVENT() to create these, otherwise it bloats the kernel.

Quoted 1 line

-- Steve

OK, I'll do that.

Thanks,
Koki Sanagi.

Quoted 27 lines
Quoted 23 lines
include/trace/events/net.h new file +22 -0
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,		skbaddr		)
+		__field(	unsigned int,	len		)
+		__string(	name,		skb->dev->name	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+		__entry->len = skb->len;
+		__assign_str(name, skb->dev->name);
+	),
+
+	TP_printk("dev=%s skbaddr=%p len=%u",
+		__get_str(name), __entry->skbaddr, __entry->len)
+);
+#endif /* _TRACE_NET_H */
+
author
#16 lore raw

RFC PATCH v2 4/5 skb: add tracepoints to freeing skb

In reply to Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq.
Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +36 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +1 -0
index 34432b4..a7b4036 100644
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);
author
#17 lore raw

RFC PATCH v2 4/5 skb: add tracepoints to freeing skb

In reply to Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq.
Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +36 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +1 -0
index 34432b4..a7b4036 100644
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);
#18 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

Quoted 89 lines · Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq. Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +36 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +0 -0
index 34432b4..a7b4036 100644

net/core/skbuff.c void consume_skb(struct sk_buff *skb) · line 472

Quoted 7 lines
net/core/skbuff.c +1 -0
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);

You might add a trace point to skb_free_datagram_locked() too, since it contains an inlined consume_skb()

author
#19 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

Quoted 93 lines · Eric Dumazet
Quoted 92 lines · Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq. Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +36 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +1 -0
index 34432b4..a7b4036 100644
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
Quoted 9 lines

net/core/skbuff.c void consume_skb(struct sk_buff *skb) · line 472

Quoted 4 lines
net/core/skbuff.c +0 -0
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);

You might add a trace point to skb_free_datagram_locked() too, since it contains an inlined consume_skb()

I think it is contrary.
skb_free_datagram_locked() contains consume_skb(), so tracepoint isn't needed. Because skb_free_datagram_locked() can be traced by trace_consume_skb().

#20 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

Quoted 5 lines · Koki Sanagi
Quoted 3 lines

You might add a trace point to skb_free_datagram_locked() too, since it contains an inlined consume_skb()

I think it is contrary.

I think you are _very_ wrong.

Quoted 5 lines

skb_free_datagram_locked() contains consume_skb(), so tracepoint isn't needed. Because skb_free_datagram_locked() can be traced by trace_consume_skb().

Koki, it would be good if you worked on net-next-2.6, so that my comment applies.

Also, not sending this kind of patches on netdev is not going to help very much.

Who is supposed to review them on lkml and Ack them ?

Nobody.

Please build your future network related patches against net-next-2.6, and send them to nedev and David Miller, the official network maintainer, as stated in MAINTAINERS file.

NETWORKING [GENERAL]

M:      "David S. Miller" <[email protected]>
L:      [email protected]
W:      http://www.linuxfoundation.org/en/Net
W:      http://patchwork.ozlabs.org/project/netdev/list/
T:      git git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6.git
T:      git git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next-2.6.git
S:      Maintained
F:      net/
F:      include/net/
F:      include/linux/in.h
F:      include/linux/net.h
F:      include/linux/netdevice.h
author
#21 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

Quoted 10 lines · Eric Dumazet
Quoted 5 lines · Koki Sanagi
Quoted 3 lines

You might add a trace point to skb_free_datagram_locked() too, since it contains an inlined consume_skb()

I think it is contrary.

I think you are _very_ wrong.

Quoted 8 lines
Quoted 5 lines

skb_free_datagram_locked() contains consume_skb(), so tracepoint isn't needed. Because skb_free_datagram_locked() can be traced by trace_consume_skb().

Koki, it would be good if you worked on net-next-2.6, so that my comment applies.

Yes, I am very wrong... I saw skb_free_datagram_locked() at linux-2.6.34. It would be good to add tracepoint to it.

Quoted 12 lines

Also, not sending this kind of patches on netdev is not going to help very much.

Who is supposed to review them on lkml and Ack them ?

Nobody.

Please build your future network related patches against net-next-2.6, and send them to nedev and David Miller, the official network maintainer, as stated in MAINTAINERS file.

NETWORKING [GENERAL]

Quoted 12 lines
M:      "David S. Miller" <[email protected]>
L:      [email protected]
W:      http://www.linuxfoundation.org/en/Net
W:      http://patchwork.ozlabs.org/project/netdev/list/
T:      git git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-2.6.git
T:      git git://git.kernel.org/pub/scm/linux/kernel/git/davem/net-next-2.6.git
S:      Maintained
F:      net/
F:      include/net/
F:      include/linux/in.h
F:      include/linux/net.h
F:      include/linux/netdevice.h

Yes, my submitting this time has many improper things(address, format and description...). I'll check and modify them next time.

Thanks,
Koki Sanagi.

Quoted 8 lines

--
To unsubscribe from this list: send the line "unsubscribe netdev" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html

maintainer
#22 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

In reply to Koki Sanagi
Quoted 49 lines · Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq. Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +25 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(

include/trace/events/skb.h TRACE_EVENT(kfree_skb, · line 72

Quoted 10 lines
include/trace/events/skb.h +10 -0
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);

These two tracepoints are also identical in body. Please use DECLARE_EVENT_CLASS() and DEFINE_EVENT() instead.

-- Steve

Quoted 42 lines
include/trace/events/skb.h +1 -0
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +1 -1
index 34432b4..a7b4036 100644
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);
 
--

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

author
#23 lore raw

Re: [RFC PATCH v2 4/5] skb: add tracepoints to freeing skb

Quoted 64 lines · Steven Rostedt
Quoted 49 lines · Koki Sanagi

This patch adds tracepoint to consume_skb and dev_kfree_skb_irq. Combinating with tracepoint on dev_hard_start_xmit, we can check how long it takes to free transmited packets. And using it, we can calculate how many packets driver had at that time. It is useful when a drop of transmited packet is a problem.

          <idle>-0     [001] 241409.218333: consume_skb: skbaddr=dd6b2fb8
          <idle>-0     [001] 241409.490555: dev_kfree_skb_irq: skbaddr=f5e29840
Signed-off-by Koki Sanagi <[email protected]>

---
include/trace/events/skb.h | 36 ++++++++++++++++++++++++++++++++++++

 net/core/dev.c             |    2 ++
 net/core/skbuff.c          |    1 +
 3 files changed, 39 insertions(+), 0 deletions(-)
include/trace/events/skb.h +25 -0
index 4b2be6d..6ab5b34 100644
@@ -35,6 +35,42 @@ TRACE_EVENT(kfree_skb,
 		__entry->skbaddr, __entry->protocol, __entry->location)
 );
 
+TRACE_EVENT(consume_skb,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);
+
+TRACE_EVENT(dev_kfree_skb_irq,
+
+	TP_PROTO(struct sk_buff *skb),
+
+	TP_ARGS(skb),
+
+	TP_STRUCT__entry(

include/trace/events/skb.h TRACE_EVENT(kfree_skb, · line 72

Quoted 10 lines
include/trace/events/skb.h +10 -0
+		__field(	void *,	skbaddr	)
+	),
+
+	TP_fast_assign(
+		__entry->skbaddr = skb;
+	),
+
+	TP_printk("skbaddr=%p",
+		__entry->skbaddr)
+);

These two tracepoints are also identical in body. Please use DECLARE_EVENT_CLASS() and DEFINE_EVENT() instead.

Quoted 2 lines

-- Steve

OK, I'll do that.

Thanks,
Koki Sanagi.

Quoted 46 lines
Quoted 42 lines
include/trace/events/skb.h +1 -0
+
 TRACE_EVENT(skb_copy_datagram_iovec,
 
 	TP_PROTO(const struct sk_buff *skb, int len),
net/core/dev.c +2 -0
index 4b64b21..807b1ca 100644
@@ -131,6 +131,7 @@
 #include <linux/random.h>
 #include <trace/events/napi.h>
 #include <trace/events/net.h>
+#include <trace/events/skb.h>
 #include <linux/pci.h>
 
 #include "net-sysfs.h"

@@ -1580,6 +1581,7 @@ void dev_kfree_skb_irq(struct sk_buff *skb)
 		struct softnet_data *sd;
 		unsigned long flags;
 
+		trace_dev_kfree_skb_irq(skb);
 		local_irq_save(flags);
 		sd = &__get_cpu_var(softnet_data);
 		skb->next = sd->completion_queue;
net/core/skbuff.c +1 -1
index 34432b4..a7b4036 100644
@@ -466,6 +466,7 @@ void consume_skb(struct sk_buff *skb)
 		smp_rmb();
 	else if (likely(!atomic_dec_and_test(&skb->users)))
 		return;
+	trace_consume_skb(skb);
 	__kfree_skb(skb);
 }
 EXPORT_SYMBOL(consume_skb);
 
--

To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/

author
#24 lore raw

RFC PATCH v2 5/5 perf:add a script shows a process of packet

In reply to Koki Sanagi

This perf script shows a time-chart of process of packet. Patch 0/5 shows an output of this.
If you want to use it, install perf and record perf.data like following.

#perf trace record netdev-times [script]

If you set script, perf gathers records until it ends. If not, you must Ctrl-C to stop recording.

And if you want a report from record,

#perf trace report netdev-times [options]

If you use some options, you can limit an output.
Option is below.

tx: show only process of tx packets
rx: show only process of rx packets
dev=: show a process specified with this option

In the future, I want src/dst IP(v6) address filter option. It's now under consideration/construction.

For example, if you want to show a process of received packets associated with eth3,

#perf trace report netdev-times rx dev=eth3
79074.756672832sec cpu=1
irq_entry(+0.000000msec,irq=77:eth3)

         |------------softirq_raise(+0.001277msec)
irq_exit (+0.002278msec)     |
                             |
                      softirq_entry(+0.003562msec)
                             |
                             |---netif_receive_skb(+0.006279msec,len=100)
                             |            |
                             |   skb_copy_datagram_iovec(+0.038778msec, 2285:sshd)
                             |
                      napi_poll_exit(+0.017160msec, eth3)
                             |
                      softirq_exit(+0.018248msec)

This perf script helps us to analyze a process time of transmit/receive sequence.

Signed-off-by Koki Sanagi <[email protected]>
---
 tools/perf/scripts/python/bin/netdev-times-record |    7 +
 tools/perf/scripts/python/bin/netdev-times-report |    5 +
 tools/perf/scripts/python/netdev-times.py         |  495 +++++++++++++++++++++
 3 files changed, 507 insertions(+), 0 deletions(-)
tools/perf/scripts/python/bin/netdev-times-record new file +7 -0
new file mode 100644
index 0000000..1dfa8d5
@@ -0,0 +1,7 @@
+#!/bin/bash
+perf record -c 1 -f -R -a -e net:net_dev_xmit -e net:net_dev_queue	\
+		-e net:net_dev_receive -e skb:consume_skb		\
+		-e skb:dev_kfree_skb_irq -e napi:napi_poll		\
+		-e irq:irq_handler_entry -e irq:irq_handler_exit	\
+		-e irq:softirq_entry -e irq:softirq_exit		\
+		-e irq:softirq_raise -e skb:skb_copy_datagram_iovec $@
tools/perf/scripts/python/bin/netdev-times-report new file +5 -0
new file mode 100644
index 0000000..ecc8122
@@ -0,0 +1,5 @@
+#!/bin/bash
+# description: displayi a process of packet and processing time
+# args: tx rx dev src dst
+
+perf trace -s ~/libexec/perf-core/scripts/python/netdev-times.py $@
tools/perf/scripts/python/netdev-times.py new file +495 -0

495 lines not on this page · raw message

author
#25 lore raw

RFC PATCH v2 5/5 perf:add a script shows a process of packet

In reply to Koki Sanagi

This perf script shows a time-chart of process of packet. Patch 0/5 shows an output of this.
If you want to use it, install perf and record perf.data like following.

#perf trace record netdev-times [script]

If you set script, perf gathers records until it ends. If not, you must Ctrl-C to stop recording.

And if you want a report from record,

#perf trace report netdev-times [options]

If you use some options, you can limit an output.
Option is below.

tx: show only process of tx packets
rx: show only process of rx packets
dev=: show a process specified with this option

In the future, I want src/dst IP(v6) address filter option. It's now under consideration/construction.

For example, if you want to show a process of received packets associated with eth3,

#perf trace report netdev-times rx dev=eth3
79074.756672832sec cpu=1
irq_entry(+0.000000msec,irq=77:eth3)

         |------------softirq_raise(+0.001277msec)
irq_exit (+0.002278msec)     |
                             |
                      softirq_entry(+0.003562msec)
                             |
                             |---netif_receive_skb(+0.006279msec,len=100)
                             |            |
                             |   skb_copy_datagram_iovec(+0.038778msec, 2285:sshd)
                             |
                      napi_poll_exit(+0.017160msec, eth3)
                             |
                      softirq_exit(+0.018248msec)

This perf script helps us to analyze a process time of transmit/receive sequence.

Signed-off-by Koki Sanagi <[email protected]>
---
 tools/perf/scripts/python/bin/netdev-times-record |    7 +
 tools/perf/scripts/python/bin/netdev-times-report |    5 +
 tools/perf/scripts/python/netdev-times.py         |  495 +++++++++++++++++++++
 3 files changed, 507 insertions(+), 0 deletions(-)
tools/perf/scripts/python/bin/netdev-times-record new file +7 -0
new file mode 100644
index 0000000..1dfa8d5
@@ -0,0 +1,7 @@
+#!/bin/bash
+perf record -c 1 -f -R -a -e net:net_dev_xmit -e net:net_dev_queue	\
+		-e net:net_dev_receive -e skb:consume_skb		\
+		-e skb:dev_kfree_skb_irq -e napi:napi_poll		\
+		-e irq:irq_handler_entry -e irq:irq_handler_exit	\
+		-e irq:softirq_entry -e irq:softirq_exit		\
+		-e irq:softirq_raise -e skb:skb_copy_datagram_iovec $@
tools/perf/scripts/python/bin/netdev-times-report new file +5 -0
new file mode 100644
index 0000000..ecc8122
@@ -0,0 +1,5 @@
+#!/bin/bash
+# description: displayi a process of packet and processing time
+# args: tx rx dev src dst
+
+perf trace -s ~/libexec/perf-core/scripts/python/netdev-times.py $@
tools/perf/scripts/python/netdev-times.py new file +495 -0

495 lines not on this page · raw message