[Cerowrt-devel] CeroWrt 3.10.18-1 Field Report

Wed Nov 13 08:56:56 EST 2013

Hi Richard,

thanks for doing this.

On Nov 13, 2013, at 05:21 , "Richard E. Brown" <richb.hanover at gmail.com> wrote:

> 
> On Nov 12, 2013, at 4:11 AM, Sebastian Moeller <moeller0 at gmx.de> wrote:
> 
>>> - The kernel.log shows lots of the stack traces below: 2-5 per second on a long-term basis. 
>> 
>> 	These look quite weird, the error is a slow patch warning from hfsc_schedule_watchdog . But, hfsc is the queuing discipline used by stock OpenWrt, cerowrt , so far, has only used HTB (last I checked was cerowrt 3.10.11-3). So my guess is that you were running the default QOS system instead (or worse in addition) to cerowrt's. It would be great to see the output of:
>> tc -d qdisc ; tc -s class show dev ifb0 ; tc -s class show dev ge00
>> to check what is up with the AQM system...
> 
> Here’s the output as requested from my router that started out as 3.7.5-2 with QoS enabled, and then was flashed via sysupgrade through the web GUI to 3.10.18-1, preserving the settings. 
> 
> Rich
> -----------------------------------------------------
> 
> root at cerowrt:~# tc -d qdisc ; tc -s class show dev ifb0 ; tc -s class show dev ge00
> qdisc fq_codel a: dev se00 root refcnt 2 limit 1000p flows 1024 quantum 1000 target 5.0ms interval 100.0ms ecn
> qdisc htb 1: dev ge00 root refcnt 2 r2q 10 default 10 direct_packets_stat 0 ver 3.17
> qdisc fq_codel 110: dev ge00 parent 1:10 limit 600p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc ingress ffff: dev ge00 parent ffff:fff1 ----------------
> qdisc mq 1: dev sw00 root
> qdisc fq_codel 10: dev sw00 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev sw00 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev sw00 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev sw00 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw01 root
> qdisc fq_codel 10: dev gw01 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw01 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw01 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw01 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw00 root
> qdisc fq_codel 10: dev gw00 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw00 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw00 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw00 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc hfsc 1: dev ifb0 root refcnt 2 default 30

	And here we have it a "residual" hfsc queueing discipline that somehow  was left over from QOS, this caused the hfsc watchdog errors.

> qdisc fq_codel 100: dev ifb0 parent 1:10 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 200: dev ifb0 parent 1:20 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 300: dev ifb0 parent 1:30 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 400: dev ifb0 parent 1:40 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc mq 1: dev sw10 root
> qdisc fq_codel 10: dev sw10 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev sw10 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev sw10 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev sw10 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw11 root
> qdisc fq_codel 10: dev gw11 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw11 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw11 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw11 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw10 root
> qdisc fq_codel 10: dev gw10 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw10 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw10 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw10 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms

	The number of fq_codels on all interfaces are cerowrt's work, as is the htb on ge00

> class hfsc 1: root
> Sent 0 bytes 0 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 0 level 2
> 
> class hfsc 1:1 parent 1: sc m1 0bit d 0us m2 6000Kbit ul m1 0bit d 0us m2 6000Kbit
> Sent 0 bytes 0 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 2 work 260 bytes level 1
> 
> class hfsc 1:10 parent 1:1 leaf 100: rt m1 1360Kbit d 325us m2 600000bit ls m1 1360Kbit d 325us m2 3333Kbit ul m1 0bit d 0us m2 6000Kbit
> Sent 0 bytes 0 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 0 level 0
> 
> class hfsc 1:20 parent 1:1 leaf 200: rt m1 3126Kbit d 325us m2 3000Kbit ls m1 3126Kbit d 325us m2 1666Kbit ul m1 0bit d 0us m2 6000Kbit
> Sent 0 bytes 0 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 0 level 0
> 
> class hfsc 1:30 parent 1:1 leaf 300: ls m1 0bit d 100.0ms m2 833000bit ul m1 0bit d 0us m2 6000Kbit
> Sent 260 bytes 2 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 2 work 260 bytes level 0
> 
> class hfsc 1:40 parent 1:1 leaf 400: ls m1 0bit d 200.0ms m2 166000bit ul m1 0bit d 0us m2 6000Kbit
> Sent 0 bytes 0 pkt (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
> period 0 level 0
> 
> class fq_codel 300:22f parent 300:
> (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
>  deficit 40 count 0 lastcount 0 ldelay 15us
> class htb 1:10 parent 1:1 leaf 110: prio 0 rate 650000bit ceil 650000bit burst 1599b cburst 1599b
> Sent 54458 bytes 263 pkt (dropped 0, overlimits 0 requeues 0)
> rate 1984bit 1pps backlog 0b 0p requeues 0
> lended: 263 borrowed: 0 giants: 0
> tokens: 244610 ctokens: 244610
> 
> class htb 1:1 root rate 650000bit ceil 650000bit burst 1599b cburst 1599b
> Sent 54458 bytes 263 pkt (dropped 0, overlimits 0 requeues 0)
> rate 1984bit 1pps backlog 0b 0p requeues 0
> lended: 0 borrowed: 0 giants: 0
> tokens: 244610 ctokens: 244610
> 
> class fq_codel 110:2e7 parent 110:
> (dropped 0, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
>  deficit -55 count 0 lastcount 0 ldelay 12us
> root at cerowrt:~#

	So as we expected the preserved QOS setting did not work well with cerowrt's defaults.

> 
> I then reflashed 3.7.5-2, and disabled the QoS setting from the web GUI, and then flashed via sysupgrade through the web GUI to 3.10.18-1, again preserving the settings. I got these results:
> 
> root at cerowrt:~# tc -d qdisc ; tc -s class show dev ifb0 ; tc -s class show dev ge00
> qdisc fq_codel a: dev se00 root refcnt 2 limit 1000p flows 1024 quantum 1000 target 5.0ms interval 100.0ms ecn
> qdisc htb 1: dev ge00 root refcnt 2 r2q 10 default 10 direct_packets_stat 0 ver 3.17
> qdisc fq_codel 110: dev ge00 parent 1:10 limit 600p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc ingress ffff: dev ge00 parent ffff:fff1 ----------------
> qdisc htb 1: dev ifb0 root refcnt 2 r2q 10 default 10 direct_packets_stat 0 ver 3.17

	And now we also have htb on ifb0, so this is a consistent cerowrt state. I now begin to understand why Dave recommends against using the "keep configuration" setting for sys upgrade :) there is just too much in flux for it to work for all sub packages. That said it should be possible to restrict the set of kept settings to those settings that should not differ between cerowrt and openWRT (I think the PPPoE setting should qualify). But I have not looked into that yet.

> qdisc fq_codel 110: dev ifb0 parent 1:10 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc mq 1: dev sw00 root
> qdisc fq_codel 10: dev sw00 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev sw00 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev sw00 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev sw00 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw01 root
> qdisc fq_codel 10: dev gw01 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw01 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw01 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw01 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc fq_codel a: dev pppoe-ge00 root refcnt 2 limit 1000p flows 1024 quantum 1000 target 5.0ms interval 100.0ms ecn
> qdisc mq 1: dev gw00 root
> qdisc fq_codel 10: dev gw00 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw00 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw00 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw00 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev sw10 root
> qdisc fq_codel 10: dev sw10 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev sw10 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev sw10 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev sw10 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw11 root
> qdisc fq_codel 10: dev gw11 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw11 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw11 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw11 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> qdisc mq 1: dev gw10 root
> qdisc fq_codel 10: dev gw10 parent 1:1 limit 800p flows 1024 quantum 500 target 10.0ms interval 100.0ms
> qdisc fq_codel 20: dev gw10 parent 1:2 limit 800p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 30: dev gw10 parent 1:3 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms ecn
> qdisc fq_codel 40: dev gw10 parent 1:4 limit 1000p flows 1024 quantum 300 target 5.0ms interval 100.0ms
> class htb 1:10 parent 1:1 leaf 110: prio 0 rate 6000Kbit ceil 6000Kbit burst 1599b cburst 1599b
> Sent 69125382 bytes 210311 pkt (dropped 0, overlimits 0 requeues 0)
> rate 2254Kbit 991pps backlog 0b 0p requeues 0
> lended: 210311 borrowed: 0 giants: 0
> tokens: 4767 ctokens: 4767
> 
> class htb 1:1 root rate 6000Kbit ceil 6000Kbit burst 1599b cburst 1599b
> Sent 69125382 bytes 210311 pkt (dropped 0, overlimits 0 requeues 0)
> rate 2254Kbit 991pps backlog 0b 0p requeues 0
> lended: 0 borrowed: 0 giants: 0
> tokens: 4767 ctokens: 4767
> 
> class fq_codel 110:292 parent 110:
> (dropped 26, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
>  deficit -709 count 1 lastcount 1 ldelay 10us
> class htb 1:10 parent 1:1 leaf 110: prio 0 rate 650000bit ceil 650000bit burst 1599b cburst 1599b
> Sent 14582488 bytes 192897 pkt (dropped 5, overlimits 0 requeues 0)
> rate 541856bit 909pps backlog 0b 0p requeues 0
> lended: 192897 borrowed: 0 giants: 0
> tokens: 276028 ctokens: 276028
> 
> class htb 1:1 root rate 650000bit ceil 650000bit burst 1599b cburst 1599b
> Sent 14582488 bytes 192897 pkt (dropped 0, overlimits 0 requeues 0)
> rate 541856bit 909pps backlog 0b 0p requeues 0
> lended: 0 borrowed: 0 giants: 0
> tokens: 276028 ctokens: 276028
> 
> class fq_codel 110:e4 parent 110:
> (dropped 8911, overlimits 0 requeues 0)
> backlog 0b 0p requeues 0
>  deficit 26 count 82 lastcount 49 ldelay 10us
> root at cerowrt:~#
> _______________________________________________
> Cerowrt-devel mailing list
> Cerowrt-devel at lists.bufferbloat.net
> https://lists.bufferbloat.net/listinfo/cerowrt-devel