debug: various debug output for fq codel

This commit is contained in:
Linus Lüssing 2018-01-17 04:03:15 +01:00
parent 2bbf79de29
commit adf9e13b68
3 changed files with 354 additions and 0 deletions

View File

@ -0,0 +1,91 @@
From: Linus Lüssing <linus.luessing@c0d3.blue>
Date: Tue, 2 Jan 2018 19:32:25 +0100
Subject: kernel: pkt_sched: fq: debug info for fq hash maps
diff --git a/target/linux/generic/patches-4.4/664-pkt_sched-fq-debug-info-for-fq-hash-maps.patch b/target/linux/generic/patches-4.4/664-pkt_sched-fq-debug-info-for-fq-hash-maps.patch
new file mode 100644
index 0000000000000000000000000000000000000000..e323590eacfdaeed886d6e39dc82250e089101cb
--- /dev/null
+++ b/target/linux/generic/patches-4.4/664-pkt_sched-fq-debug-info-for-fq-hash-maps.patch
@@ -0,0 +1,81 @@
+From 9ce795f42a2f69cf60176b310052c256b678a94c Mon Sep 17 00:00:00 2001
+From: =?UTF-8?q?Linus=20L=C3=BCssing?= <linus.luessing@c0d3.blue>
+Date: Tue, 2 Jan 2018 00:51:19 +0100
+Subject: [PATCH] pkt_sched: fq: debug info for fq hash maps
+
+By default, the hash map itself (excluding any items) is
+allocated with 1024 entries of usually about 12 byte per entry
+on 32Bit architectures (rb_root/rb_node). The code dynamically
+resizes the hash maps and also up to 256*1024 entries, so usually
+~3MB on 32B.
+
+This patch addes some debug output for hash map resizing and
+allocations. It also prevents allocating the hash maps via vmalloc,
+only allowing kmalloc.
+---
+ net/sched/sch_fq.c | 21 ++++++++++++++++-----
+ 1 file changed, 16 insertions(+), 5 deletions(-)
+
+diff --git a/net/sched/sch_fq.c b/net/sched/sch_fq.c
+index 3c6a47d66a04..a476165fa347 100644
+--- a/net/sched/sch_fq.c
++++ b/net/sched/sch_fq.c
+@@ -599,14 +599,20 @@ static void *fq_alloc_node(size_t sz, int node)
+ {
+ void *ptr;
+
+- ptr = kmalloc_node(sz, GFP_KERNEL | __GFP_REPEAT | __GFP_NOWARN, node);
+- if (!ptr)
+- ptr = vmalloc_node(sz, node);
++ printk("~~~ %s: Allocating, sz: %lu\n", __func__, sz);
++ ptr = kmalloc_node(sz, GFP_KERNEL, node);
++ if (ptr)
++ printk("~~~ %s: Allocated at: %p\n", __func__, ptr);
++ else
++ printk("~~~ %s: Allocation failed\n", __func__);
++// if (!ptr)
++// ptr = vmalloc_node(sz, node);
+ return ptr;
+ }
+
+ static void fq_free(void *addr)
+ {
++ printk("~~~ %s: Freeing memory at %p\n", __func__, addr);
+ kvfree(addr);
+ }
+
+@@ -620,6 +626,7 @@ static int fq_resize(struct Qdisc *sch, u32 log)
+ if (q->fq_root && log == q->fq_trees_log)
+ return 0;
+
++ printk("~~~ %s: sizeof(struct rb_root): %lu, log: %u\n", __func__, sizeof(struct rb_root), log);
+ /* If XPS was setup, we can allocate memory on right NUMA node */
+ array = fq_alloc_node(sizeof(struct rb_root) << log,
+ netdev_queue_numa_node_read(sch->dev_queue));
+@@ -729,6 +736,7 @@ static int fq_change(struct Qdisc *sch, struct nlattr *opt)
+
+ if (!err) {
+ sch_tree_unlock(sch);
++ printk("~~~ %s: Calling fq_resize() with log %lu\n", __func__, fq_log);
+ err = fq_resize(sch, fq_log);
+ sch_tree_lock(sch);
+ }
+@@ -776,10 +784,13 @@ static int fq_init(struct Qdisc *sch, struct nlattr *opt)
+ q->orphan_mask = 1024 - 1;
+ qdisc_watchdog_init(&q->watchdog, sch);
+
+- if (opt)
++ if (opt) {
++ printk("~~~ %s: Calling fq_change\n", __func__);
+ err = fq_change(sch, opt);
+- else
++ } else {
++ printk("~~~ %s: Calling fq_resize with log %lu\n", __func__, q->fq_trees_log);
+ err = fq_resize(sch, q->fq_trees_log);
++ }
+
+ return err;
+ }
+--
+2.11.0
+

View File

@ -0,0 +1,96 @@
From: Linus Lüssing <linus.luessing@c0d3.blue>
Date: Tue, 2 Jan 2018 19:32:58 +0100
Subject: kernel: pkt_sched: fq_codel: debug info for fq codel flow allocations
diff --git a/target/linux/generic/patches-4.4/665-0001-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allo.patch b/target/linux/generic/patches-4.4/665-0001-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allo.patch
new file mode 100644
index 0000000000000000000000000000000000000000..f679b2bf226efa2250cf8f3b8be054c7aea3872c
--- /dev/null
+++ b/target/linux/generic/patches-4.4/665-0001-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allo.patch
@@ -0,0 +1,86 @@
+From 55d3a297b281ba679aff86b8a3ad6f4f7cbc43a6 Mon Sep 17 00:00:00 2001
+From: =?UTF-8?q?Linus=20L=C3=BCssing?= <linus.luessing@c0d3.blue>
+Date: Tue, 2 Jan 2018 19:29:17 +0100
+Subject: [PATCH 1/2] pkt_sched: fq_codel: debug info for fq codel flow
+ allocations
+
+This patch adds some debug output for fq codel flow allocations.
+It also prevents allocating them via vmalloc, only allowing kmalloc.
+---
+ net/sched/sch_fq_codel.c | 36 +++++++++++++++++++++++++++++++++---
+ 1 file changed, 33 insertions(+), 3 deletions(-)
+
+diff --git a/net/sched/sch_fq_codel.c b/net/sched/sch_fq_codel.c
+index 0e211d729d43..aac564433d40 100644
+--- a/net/sched/sch_fq_codel.c
++++ b/net/sched/sch_fq_codel.c
+@@ -25,6 +25,15 @@
+ #include <net/pkt_sched.h>
+ #include <net/codel.h>
+
++
++static inline char *SCH_DEV_NAME(struct Qdisc *sch)
++{
++ if (sch && sch->dev_queue && sch->dev_queue->dev && sch->dev_queue->dev->name)
++ return sch->dev_queue->dev->name;
++ else
++ return "<unknown>";
++}
++
+ /* Fair Queue CoDel.
+ *
+ * Principles :
+@@ -443,15 +452,23 @@ static int fq_codel_change(struct Qdisc *sch, struct nlattr *opt)
+
+ static void *fq_codel_zalloc(size_t sz)
+ {
+- void *ptr = kzalloc(sz, GFP_KERNEL | __GFP_NOWARN);
++ void *ptr = kzalloc(sz, GFP_KERNEL);
++// void *ptr = kzalloc(sz, GFP_KERNEL | __GFP_NOWARN);
+
+- if (!ptr)
+- ptr = vzalloc(sz);
++ printk("~~~ %s: Allocating, sz: %lu\n", __func__, sz);
++ if (ptr)
++ printk("~~~ %s: Allocated at: %p\n", __func__, ptr);
++ else
++ printk("~~~ %s: Allocation failed\n", __func__);
++
++// if (!ptr)
++// ptr = vzalloc(sz);
+ return ptr;
+ }
+
+ static void fq_codel_free(void *addr)
+ {
++ printk("~~~ %s: Freeing memory at %p\n", __func__, addr);
+ kvfree(addr);
+ }
+
+@@ -488,10 +505,23 @@ static int fq_codel_init(struct Qdisc *sch, struct nlattr *opt)
+ }
+
+ if (!q->flows) {
++ printk("~~~ %s: %s: Calling fq_codel_zalloc() with sz: %lu (cnt: %u, szof(): %lu) for flows\n",
++ __func__,
++ SCH_DEV_NAME(sch),
++ q->flows_cnt * sizeof(struct fq_codel_flow),
++ q->flows_cnt, sizeof(struct fq_codel_flow));
++
+ q->flows = fq_codel_zalloc(q->flows_cnt *
+ sizeof(struct fq_codel_flow));
+ if (!q->flows)
+ return -ENOMEM;
++
++ printk("~~~ %s: %s: Calling fq_codel_zalloc() with sz: %lu (cnt: %u, szof(): %lu) for backlogs\n",
++ __func__,
++ SCH_DEV_NAME(sch),
++ q->flows_cnt * sizeof(u32),
++ q->flows_cnt, sizeof(u32));
++
+ q->backlogs = fq_codel_zalloc(q->flows_cnt * sizeof(u32));
+ if (!q->backlogs) {
+ fq_codel_free(q->flows);
+--
+2.11.0
+

View File

@ -0,0 +1,167 @@
From: Linus Lüssing <linus.luessing@c0d3.blue>
Date: Wed, 3 Jan 2018 06:33:18 +0100
Subject: kernel: pkt_sched: fq_codel: debug/asserts for fq codel memory_usage
diff --git a/target/linux/generic/patches-4.4/665-0002-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory.patch b/target/linux/generic/patches-4.4/665-0002-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory.patch
new file mode 100644
index 0000000000000000000000000000000000000000..2dd5c1e2e20f7533e1b27e4d795e23cdeef8f20e
--- /dev/null
+++ b/target/linux/generic/patches-4.4/665-0002-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory.patch
@@ -0,0 +1,157 @@
+From 0176de697a170b70591609f3e6ff8b178c16acb6 Mon Sep 17 00:00:00 2001
+From: =?UTF-8?q?Linus=20L=C3=BCssing?= <linus.luessing@c0d3.blue>
+Date: Wed, 3 Jan 2018 06:27:10 +0100
+Subject: [PATCH 2/2] pkt_sched: fq_codel: debug/asserts for fq codel
+ memory_usage usage
+
+---
+ net/sched/sch_fq_codel.c | 55 +++++++++++++++++++++++++++++++++++++++++++++++-
+ 1 file changed, 54 insertions(+), 1 deletion(-)
+
+diff --git a/net/sched/sch_fq_codel.c b/net/sched/sch_fq_codel.c
+index aac564433d40..56c440ca88e2 100644
+--- a/net/sched/sch_fq_codel.c
++++ b/net/sched/sch_fq_codel.c
+@@ -154,6 +154,7 @@ static unsigned int fq_codel_drop(struct Qdisc *sch, unsigned int max_packets)
+ struct fq_codel_flow *flow;
+ unsigned int threshold;
+ unsigned int mem = 0;
++ unsigned int old_mem;
+
+ /* Queue is full! Find the fat flow and drop packet(s) from it.
+ * This might sound expensive, but with 1024 flows, we scan
+@@ -178,12 +179,29 @@ static unsigned int fq_codel_drop(struct Qdisc *sch, unsigned int max_packets)
+ do {
+ skb = dequeue_head(flow);
+ len += qdisc_pkt_len(skb);
++
++ if (skb->truesize > 3000)
++ printk_ratelimited("~~~ %s: %s: dropping packet with weird truesize? skb->truesize %u (skb->len: %u, skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++ if (skb->truesize < skb->len)
++ printk_ratelimited("~~~ %s: %s: dropping packet with invalid truesize? skb->truesize %u vs. skb->len %u (skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++
++ old_mem = mem;
+ mem += skb->truesize;
++
++ if (mem < old_mem)
++ printk_ratelimited("~~~ %s: %s: oh oh, overflow happened here... mem: %u, old_mem: %u, skb->truesize: %u\n", __func__, SCH_DEV_NAME(sch), mem, old_mem, skb->truesize);
++ else if (old_mem + skb->truesize != mem)
++ printk_ratelimited("~~~ %s: %s: locking error? mem: %u, old_mem: %u, skb->truesize: %u\n", __func__, SCH_DEV_NAME(sch), mem, old_mem, skb->truesize);
++
+ kfree_skb(skb);
+ } while (++i < max_packets && len < threshold);
+
+ flow->dropped += i;
+ q->backlogs[idx] -= len;
++
++ if (mem > q->memory_usage)
++ printk_ratelimited("~~~ %s: %s: oh, oh, underflow to happen for memory_usage... q->memory_usage: %u, mem: %u\n", __func__, SCH_DEV_NAME(sch), q->memory_usage, mem);
++
+ q->memory_usage -= mem;
+ sch->qstats.drops += i;
+ sch->qstats.backlog -= len;
+@@ -208,6 +226,7 @@ static int fq_codel_enqueue(struct sk_buff *skb, struct Qdisc *sch)
+ int uninitialized_var(ret);
+ unsigned int pkt_len;
+ bool memory_limited;
++ u32 old_memory_usage;
+
+ idx = fq_codel_classify(skb, sch, &ret);
+ if (idx == 0) {
+@@ -230,7 +249,20 @@ static int fq_codel_enqueue(struct sk_buff *skb, struct Qdisc *sch)
+ flow->deficit = q->quantum;
+ flow->dropped = 0;
+ }
++
++ if (skb->truesize > 3000)
++ printk_ratelimited("~~~ %s: %s: enqueueing packet with weird truesize? skb->truesize %u (skb->len: %u, skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++ if (skb->truesize < skb->len)
++ printk_ratelimited("~~~ %s: %s: enqueueing packet with invalid truesize? skb->truesize %u vs. skb->len %u (skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++
++ old_memory_usage = q->memory_usage;
+ q->memory_usage += skb->truesize;
++
++ if (q->memory_usage < old_memory_usage)
++ printk_ratelimited("~~~ %s: %s: oh, oh, overflow happened for memory_usage... q->memory_usage: %u, skb->truesize: %u, old memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->memory_usage, skb->truesize, old_memory_usage);
++ else if (old_memory_usage + skb->truesize != q->memory_usage)
++ printk_ratelimited("~~~ %s: %s: locking error? memory_usage: %lu, old_mem_memory_usage: %lu, skb->truesize: %u\n", __func__, SCH_DEV_NAME(sch), q->memory_usage, old_memory_usage, skb->truesize);
++
+ memory_limited = q->memory_usage > q->memory_limit;
+ if (++sch->q.qlen <= sch->limit && !memory_limited)
+ return NET_XMIT_SUCCESS;
+@@ -280,6 +312,15 @@ static struct sk_buff *dequeue(struct codel_vars *vars, struct Qdisc *sch)
+ if (flow->head) {
+ skb = dequeue_head(flow);
+ q->backlogs[flow - q->flows] -= qdisc_pkt_len(skb);
++
++ if (skb->truesize > 3000)
++ printk_ratelimited("~~~ %s: %s: dequeueing packet with weird truesize? skb->truesize %u (skb->len: %u, skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++ if (skb->truesize < skb->len)
++ printk_ratelimited("~~~ %s: %s: dequeueing packet with invalid truesize? skb->truesize %u vs. skb->len %u (skb->data_len: %u)\n", __func__, SCH_DEV_NAME(sch), skb->truesize, skb->len, skb->data_len);
++
++ if (skb->truesize > q->memory_usage)
++ printk_ratelimited("~~~ %s: %s: oh, oh, underflow to happen for memory_usage... q->memory_usage: %u, skb->truesize: %u\n", __func__, SCH_DEV_NAME(sch), q->memory_usage, skb->truesize);
++
+ q->memory_usage -= skb->truesize;
+ sch->q.qlen--;
+ }
+@@ -349,6 +390,9 @@ static void fq_codel_reset(struct Qdisc *sch)
+
+ INIT_LIST_HEAD(&q->new_flows);
+ INIT_LIST_HEAD(&q->old_flows);
++
++ printk("~~~ %s: %s: flows_cnt: %lu, &flows: %p\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->flows);
++
+ for (i = 0; i < q->flows_cnt; i++) {
+ struct fq_codel_flow *flow = q->flows + i;
+
+@@ -434,6 +478,8 @@ static int fq_codel_change(struct Qdisc *sch, struct nlattr *opt)
+ if (tb[TCA_FQ_CODEL_MEMORY_LIMIT])
+ q->memory_limit = min(1U << 31, nla_get_u32(tb[TCA_FQ_CODEL_MEMORY_LIMIT]));
+
++ printk("~~~ %s: %s: (1) flows_cnt: %u, memory_limit: %u, memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->memory_limit, q->memory_usage);
++
+ while (sch->q.qlen > sch->limit ||
+ q->memory_usage > q->memory_limit) {
+ struct sk_buff *skb = fq_codel_dequeue(sch);
+@@ -446,6 +492,8 @@ static int fq_codel_change(struct Qdisc *sch, struct nlattr *opt)
+ q->cstats.drop_count = 0;
+ q->cstats.drop_len = 0;
+
++ printk("~~~ %s: %s: (2) flows_cnt: %u, memory_limit: %u, memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->memory_limit, q->memory_usage);
++
+ sch_tree_unlock(sch);
+ return 0;
+ }
+@@ -504,6 +552,8 @@ static int fq_codel_init(struct Qdisc *sch, struct nlattr *opt)
+ return err;
+ }
+
++ printk("~~~ %s: %s: flows_cnt: %u, memory_limit: %u, memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->memory_limit, q->memory_usage);
++
+ if (!q->flows) {
+ printk("~~~ %s: %s: Calling fq_codel_zalloc() with sz: %lu (cnt: %u, szof(): %lu) for flows\n",
+ __func__,
+@@ -513,8 +563,10 @@ static int fq_codel_init(struct Qdisc *sch, struct nlattr *opt)
+
+ q->flows = fq_codel_zalloc(q->flows_cnt *
+ sizeof(struct fq_codel_flow));
+- if (!q->flows)
++ if (!q->flows) {
++ printk("~~~ %s: %s: Allocation failure for flows! flows_cnt: %u, memory_limit: %u, memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->memory_limit, q->memory_usage);
+ return -ENOMEM;
++ }
+
+ printk("~~~ %s: %s: Calling fq_codel_zalloc() with sz: %lu (cnt: %u, szof(): %lu) for backlogs\n",
+ __func__,
+@@ -524,6 +576,7 @@ static int fq_codel_init(struct Qdisc *sch, struct nlattr *opt)
+
+ q->backlogs = fq_codel_zalloc(q->flows_cnt * sizeof(u32));
+ if (!q->backlogs) {
++ printk("~~~ %s: %s: Allocation failure for backlogs! flows_cnt: %u, memory_limit: %u, memory_usage: %u\n", __func__, SCH_DEV_NAME(sch), q->flows_cnt, q->memory_limit, q->memory_usage);
+ fq_codel_free(q->flows);
+ return -ENOMEM;
+ }
+--
+2.11.0
+