From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mout.gmx.net (mout.gmx.net [212.227.15.19]) (using TLSv1 with cipher DHE-RSA-AES128-SHA (128/128 bits)) (Client CN "mout.gmx.net", Issuer "TeleSec ServerPass DE-1" (verified OK)) by huchra.bufferbloat.net (Postfix) with ESMTPS id 332BE21F159 for ; Wed, 13 Nov 2013 05:56:59 -0800 (PST) Received: from u-084-c226.eap.uni-tuebingen.de ([134.2.84.226]) by mail.gmx.com (mrgmx101) with ESMTPSA (Nemesis) id 0LcWSI-1VGdqA0Dd0-00jrYA for ; Wed, 13 Nov 2013 14:56:56 +0100 Content-Type: text/plain; charset=windows-1252 Mime-Version: 1.0 (Mac OS X Mail 6.6 \(1510\)) From: Sebastian Moeller In-Reply-To: <8DD9AC0D-6606-4E7A-A60B-59D126D8D847@gmail.com> Date: Wed, 13 Nov 2013 14:56:56 +0100 Content-Transfer-Encoding: quoted-printable Message-Id: References: <56442F41-68E0-495A-B6B3-87AC2910EBED@gmail.com> <47AA0EBF-0886-444B-9A04-EB23105A8A3B@gmx.de> <8DD9AC0D-6606-4E7A-A60B-59D126D8D847@gmail.com> To: "Richard E. Brown" X-Mailer: Apple Mail (2.1510) X-Provags-ID: V03:K0:/bLVBv3x7bvHJQ4fse7CJ56TdsVa1/m5pDY81B4quSyGcI5i05t ZlTKc0PNbJ0GcWJnpfX+5mhc05m32vI47+FySLcO5X7pqxb0oshmsF83CFG2qgPzUz6P17m qbJc+JEbA8+m8OAMh+zSja7XN/aybNaXeZ6ZASAb5fMdFohr3jlRDH7JmgIIblwtcqnqzwP CP0Qi2TrHKPTZ80Brr47A== Cc: cerowrt-devel@lists.bufferbloat.net Subject: Re: [Cerowrt-devel] CeroWrt 3.10.18-1 Field Report X-BeenThere: cerowrt-devel@lists.bufferbloat.net X-Mailman-Version: 2.1.13 Precedence: list List-Id: Development issues regarding the cerowrt test router project List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 13 Nov 2013 13:57:00 -0000 Hi Richard, thanks for doing this. On Nov 13, 2013, at 05:21 , "Richard E. Brown" = wrote: >=20 > On Nov 12, 2013, at 4:11 AM, Sebastian Moeller = wrote: >=20 >>> - The kernel.log shows lots of the stack traces below: 2-5 per = second on a long-term basis.=20 >>=20 >> 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... >=20 > Here=92s 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.=20 >=20 > Rich > ----------------------------------------------------- >=20 > root@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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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@cerowrt:~# So as we expected the preserved QOS setting did not work well = with cerowrt's defaults. >=20 > 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: >=20 > root@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 >=20 > 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 >=20 > 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 >=20 > 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 >=20 > 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@cerowrt:~# > _______________________________________________ > Cerowrt-devel mailing list > Cerowrt-devel@lists.bufferbloat.net > https://lists.bufferbloat.net/listinfo/cerowrt-devel