[net-next 1/2] qdisc: add tracepoint qdisc:qdisc_enqueue for enqueued SKBs

From: Tonghao Zhang <redacted>

This tracepoint can work with qdisc:qdisc_dequeue to measure
packets latency in qdisc queue. In some case, for example,
if TX queues are stopped or frozen, sch_direct_xmit will invoke
the dev_requeue_skb to requeue SKBs to qdisc->gso_skb, that may
delay the SKBs in qdisc queue.

With this patch, we can measure packets latency.

Signed-off-by: Tonghao Zhang <redacted>
---
 include/net/pkt_sched.h      |  4 ++++
 include/trace/events/qdisc.h | 32 ++++++++++++++++++++++++++++++++
 net/core/dev.c               |  4 ++--
 net/sched/sch_generic.c      | 11 +++++++++++
 4 files changed, 49 insertions(+), 2 deletions(-)

diff --git a/include/net/pkt_sched.h b/include/net/pkt_sched.h
index 6d7b12cba015..66411b4ff284 100644
--- a/include/net/pkt_sched.h
+++ b/include/net/pkt_sched.h

@@ -133,6 +133,10 @@ static inline void qdisc_run(struct Qdisc *q)
 	}
 }
 
+int qdisc_enqueue_skb(struct netdev_queue *txq, struct Qdisc *q,
+		      struct sk_buff *skb,
+		      struct sk_buff **to_free);
+
 /* Calculate maximal size of packet seen by hard_start_xmit
    routine of this device.
  */

diff --git a/include/trace/events/qdisc.h b/include/trace/events/qdisc.h
index 330d32d84485..b0e76237bb74 100644
--- a/include/trace/events/qdisc.h
+++ b/include/trace/events/qdisc.h

@@ -11,6 +11,38 @@
 #include <linux/pkt_sched.h>
 #include <net/sch_generic.h>
 
+TRACE_EVENT(qdisc_enqueue,
+
+	TP_PROTO(struct Qdisc *qdisc, const struct netdev_queue *txq,
+		 struct sk_buff *skb, int ret),
+
+	TP_ARGS(qdisc, txq, skb, ret),
+
+	TP_STRUCT__entry(
+		__field(	struct Qdisc *,		qdisc	)
+		__field(const	struct netdev_queue *,	txq	)
+		__field(	void *,			skbaddr	)
+		__field(	int,			ifindex	)
+		__field(	u32,			handle	)
+		__field(	u32,			parent	)
+		__field(	int,			ret	)
+	),
+
+	TP_fast_assign(
+		__entry->qdisc		= qdisc;
+		__entry->txq		= txq;
+		__entry->skbaddr	= skb;
+		__entry->ifindex	= txq->dev ? txq->dev->ifindex : 0;
+		__entry->handle		= qdisc->handle;
+		__entry->parent		= qdisc->parent;
+		__entry->ret		= ret;
+	),
+
+	TP_printk("enqueue ifindex=%d qdisc handle=0x%X parent=0x%X skbaddr=%p ret=%d",
+		  __entry->ifindex, __entry->handle, __entry->parent,
+		  __entry->skbaddr, __entry->ret)
+);
+
 TRACE_EVENT(qdisc_dequeue,
 
 	TP_PROTO(struct Qdisc *qdisc, const struct netdev_queue *txq,

diff --git a/net/core/dev.c b/net/core/dev.c
index 50531a2d0b20..78efac6b2e60 100644
--- a/net/core/dev.c
+++ b/net/core/dev.c

@@ -3852,7 +3852,7 @@ static inline int __dev_xmit_skb(struct sk_buff *skb, struct Qdisc *q,
 	qdisc_calculate_pkt_len(skb, q);
 
 	if (q->flags & TCQ_F_NOLOCK) {
-		rc = q->enqueue(skb, q, &to_free) & NET_XMIT_MASK;
+		rc = qdisc_enqueue_skb(txq, q, skb, &to_free);
 		if (likely(!netif_xmit_frozen_or_stopped(txq)))
 			qdisc_run(q);
 

@@ -3896,7 +3896,7 @@ static inline int __dev_xmit_skb(struct sk_buff *skb, struct Qdisc *q,
 		qdisc_run_end(q);
 		rc = NET_XMIT_SUCCESS;
 	} else {
-		rc = q->enqueue(skb, q, &to_free) & NET_XMIT_MASK;
+		rc = qdisc_enqueue_skb(txq, q, skb, &to_free);
 		if (qdisc_run_begin(q)) {
 			if (unlikely(contended)) {
 				spin_unlock(&q->busylock);

diff --git a/net/sched/sch_generic.c b/net/sched/sch_generic.c
index e9c0afc8becc..75605075178f 100644
--- a/net/sched/sch_generic.c
+++ b/net/sched/sch_generic.c

@@ -415,6 +415,17 @@ void __qdisc_run(struct Qdisc *q)
 	}
 }
 
+int qdisc_enqueue_skb(struct netdev_queue *txq, struct Qdisc *q,
+		      struct sk_buff *skb,
+		      struct sk_buff **to_free)
+{
+	int ret;
+
+	ret = q->enqueue(skb, q, to_free) & NET_XMIT_MASK;
+	trace_qdisc_enqueue(q, txq, skb, ret);
+	return ret;
+}
+
 unsigned long dev_trans_start(struct net_device *dev)
 {
 	unsigned long val, res;

-- 
2.27.0

From: Tonghao Zhang <redacted>

The main purpose of this tracepoint is to monitor what,
how many and why packets were requeued. The txq_state can
be used for determining the reason for packets requeued.

Signed-off-by: Tonghao Zhang <redacted>
---
 include/trace/events/qdisc.h | 32 ++++++++++++++++++++++++++++++++
 net/sched/sch_generic.c      |  8 +++++---
 2 files changed, 37 insertions(+), 3 deletions(-)

diff --git a/include/trace/events/qdisc.h b/include/trace/events/qdisc.h
index b0e76237bb74..c6187a8fc103 100644
--- a/include/trace/events/qdisc.h
+++ b/include/trace/events/qdisc.h

@@ -78,6 +78,38 @@ TRACE_EVENT(qdisc_dequeue,
 		  __entry->txq_state, __entry->packets, __entry->skbaddr )
 );
 
+TRACE_EVENT(qdisc_requeue,
+
+	TP_PROTO(struct sk_buff *skb, struct Qdisc *qdisc,
+		 const struct netdev_queue *txq),
+
+	TP_ARGS(skb, qdisc, txq),
+
+	TP_STRUCT__entry(
+		__field(	struct Qdisc *,		qdisc	)
+		__field(const	struct netdev_queue *,	txq	)
+		__field(	void *,			skbaddr	)
+		__field(	int,			ifindex	)
+		__field(	u32,			handle	)
+		__field(	u32,			parent	)
+		__field(	unsigned long,		txq_state)
+	),
+
+	TP_fast_assign(
+		__entry->qdisc		= qdisc;
+		__entry->txq		= txq;
+		__entry->skbaddr	= skb;
+		__entry->ifindex	= txq->dev ? txq->dev->ifindex : 0;
+		__entry->handle		= qdisc->handle;
+		__entry->parent		= qdisc->parent;
+		__entry->txq_state	= txq->state;
+	),
+
+	TP_printk("requeue ifindex=%d qdisc handle=0x%X parent=0x%X txq_state=0x%lX skbaddr=%p",
+		  __entry->ifindex, __entry->handle, __entry->parent,
+		  __entry->txq_state, __entry->skbaddr)
+);
+
 TRACE_EVENT(qdisc_reset,
 
 	TP_PROTO(struct Qdisc *q),

diff --git a/net/sched/sch_generic.c b/net/sched/sch_generic.c
index 75605075178f..0701d1e9d221 100644
--- a/net/sched/sch_generic.c
+++ b/net/sched/sch_generic.c

@@ -137,7 +137,8 @@ static inline void qdisc_enqueue_skb_bad_txq(struct Qdisc *q,
 		spin_unlock(lock);
 }
 
-static inline void dev_requeue_skb(struct sk_buff *skb, struct Qdisc *q)
+static inline void dev_requeue_skb(struct sk_buff *skb, struct Qdisc *q,
+				   struct netdev_queue *txq)
 {
 	spinlock_t *lock = NULL;
 

@@ -149,6 +150,7 @@ static inline void dev_requeue_skb(struct sk_buff *skb, struct Qdisc *q)
 	while (skb) {
 		struct sk_buff *next = skb->next;
 
+		trace_qdisc_requeue(skb, q, txq);
 		__skb_queue_tail(&q->gso_skb, skb);
 
 		/* it's still part of the queue */

@@ -325,7 +327,7 @@ bool sch_direct_xmit(struct sk_buff *skb, struct Qdisc *q,
 		if (root_lock)
 			spin_lock(root_lock);
 
-		dev_requeue_skb(skb, q);
+		dev_requeue_skb(skb, q, txq);
 		return false;
 	}
 #endif

@@ -353,7 +355,7 @@ bool sch_direct_xmit(struct sk_buff *skb, struct Qdisc *q,
 			net_warn_ratelimited("BUG %s code %d qlen %d\n",
 					     dev->name, ret, q->q.qlen);
 
-		dev_requeue_skb(skb, q);
+		dev_requeue_skb(skb, q, txq);
 		return false;
 	}
 

-- 
2.27.0

On Sat, Jul 10, 2021 at 10:00 PM [off-list ref] wrote:

From: Tonghao Zhang <redacted>

This tracepoint can work with qdisc:qdisc_dequeue to measure
packets latency in qdisc queue. In some case, for example,
if TX queues are stopped or frozen, sch_direct_xmit will invoke
the dev_requeue_skb to requeue SKBs to qdisc->gso_skb, that may
delay the SKBs in qdisc queue.

With this patch, we can measure packets latency.

Coincidentally, we have a nearly same patch:
https://marc.info/?l=linux-netdev&m=162580785123913&w=2

Also, '%p' certainly does not work, it produces same address for
different packets. This is why we changed it to '%px', see:
https://marc.info/?l=linux-netdev&m=162580784823909&w=2

Thanks.

On Sat, Jul 10, 2021 at 10:00 PM [off-list ref] wrote:

From: Tonghao Zhang <redacted>

The main purpose of this tracepoint is to monitor what,
how many and why packets were requeued. The txq_state can
be used for determining the reason for packets requeued.

Hmm, how can I figure out the requeue is caused by
validate_xmit_skb_list() when it returns again==true?
I fail to see you trace it.

For the other case, we can figure it out by trace_net_dev_xmit().

So, in short, your patch looks useless.

Thanks.

On Mon, Jul 12, 2021 at 11:51 AM Cong Wang [off-list ref] wrote:

On Sat, Jul 10, 2021 at 10:00 PM [off-list ref] wrote:

quoted

From: Tonghao Zhang <redacted>

The main purpose of this tracepoint is to monitor what,
how many and why packets were requeued. The txq_state can
be used for determining the reason for packets requeued.

Hmm, how can I figure out the requeue is caused by
validate_xmit_skb_list() when it returns again==true?
I fail to see you trace it.

This patch looks not good.

For the other case, we can figure it out by trace_net_dev_xmit().
So, in short, your patch looks useless.

Thanks.

--
Best regards, Tonghao

On Mon, Jul 12, 2021 at 12:17 PM Tonghao Zhang [off-list ref] wrote:

On Mon, Jul 12, 2021 at 11:51 AM Cong Wang [off-list ref] wrote:

quoted

On Sat, Jul 10, 2021 at 10:00 PM [off-list ref] wrote:

quoted

From: Tonghao Zhang <redacted>

The main purpose of this tracepoint is to monitor what,
how many and why packets were requeued. The txq_state can
be used for determining the reason for packets requeued.

Hmm, how can I figure out the requeue is caused by
validate_xmit_skb_list() when it returns again==true?

Hi cong
Consider this patch again.
The main purpose of this tracepoint is to monitor what, how many and
why packets were requeued.
So should we figure out packets required by validate_xmit_skb_list or
dev_hard_start_xmit ?
because we may want to know what packets were requeued and how many.

if we should figure out, we can add more arg for trace, right ?

quoted

I fail to see you trace it.

This patch looks not good.

quoted

For the other case, we can figure it out by trace_net_dev_xmit().
So, in short, your patch looks useless.

Thanks.

--
Best regards, Tonghao

--
Best regards, Tonghao

On Mon, Jul 12, 2021 at 7:07 PM Tonghao Zhang [off-list ref] wrote:

On Mon, Jul 12, 2021 at 12:17 PM Tonghao Zhang [off-list ref] wrote:

quoted

On Mon, Jul 12, 2021 at 11:51 AM Cong Wang [off-list ref] wrote:

quoted

On Sat, Jul 10, 2021 at 10:00 PM [off-list ref] wrote:

quoted

From: Tonghao Zhang <redacted>

The main purpose of this tracepoint is to monitor what,
how many and why packets were requeued. The txq_state can
be used for determining the reason for packets requeued.

Hmm, how can I figure out the requeue is caused by
validate_xmit_skb_list() when it returns again==true?

Hi cong
Consider this patch again.
The main purpose of this tracepoint is to monitor what, how many and
why packets were requeued.
So should we figure out packets required by validate_xmit_skb_list or
dev_hard_start_xmit ?
because we may want to know what packets were requeued and how many.

if we should figure out, we can add more arg for trace, right ?

Figuring out which case is important to determine the cause,
so you have to fix it to make it useful.

Thanks.