From adf9e13b6898fccf713bb6bbb75d06cd0975e242 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Linus=20L=C3=BCssing?= Date: Wed, 17 Jan 2018 04:03:15 +0100 Subject: [PATCH] debug: various debug output for fq codel --- ...sched-fq-debug-info-for-fq-hash-maps.patch | 91 ++++++++++ ...g-info-for-fq-codel-flow-allocations.patch | 96 ++++++++++ ...ug-asserts-for-fq-codel-memory_usage.patch | 167 ++++++++++++++++++ 3 files changed, 354 insertions(+) create mode 100644 patches/lede/0072-kernel-pkt_sched-fq-debug-info-for-fq-hash-maps.patch create mode 100644 patches/lede/0073-kernel-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allocations.patch create mode 100644 patches/lede/0074-kernel-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory_usage.patch diff --git a/patches/lede/0072-kernel-pkt_sched-fq-debug-info-for-fq-hash-maps.patch b/patches/lede/0072-kernel-pkt_sched-fq-debug-info-for-fq-hash-maps.patch new file mode 100644 index 00000000..3a71c137 --- /dev/null +++ b/patches/lede/0072-kernel-pkt_sched-fq-debug-info-for-fq-hash-maps.patch @@ -0,0 +1,91 @@ +From: Linus Lüssing +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?= ++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 ++ diff --git a/patches/lede/0073-kernel-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allocations.patch b/patches/lede/0073-kernel-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allocations.patch new file mode 100644 index 00000000..94f57f39 --- /dev/null +++ b/patches/lede/0073-kernel-pkt_sched-fq_codel-debug-info-for-fq-codel-flow-allocations.patch @@ -0,0 +1,96 @@ +From: Linus Lüssing +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?= ++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 ++ #include ++ +++ +++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 ""; +++} +++ ++ /* 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 ++ diff --git a/patches/lede/0074-kernel-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory_usage.patch b/patches/lede/0074-kernel-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory_usage.patch new file mode 100644 index 00000000..d85d9ab2 --- /dev/null +++ b/patches/lede/0074-kernel-pkt_sched-fq_codel-debug-asserts-for-fq-codel-memory_usage.patch @@ -0,0 +1,167 @@ +From: Linus Lüssing +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?= ++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 ++