From owner-freebsd-mips@freebsd.org Sat Oct 31 19:47:01 2015 Return-Path: Delivered-To: freebsd-mips@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 20076A2247A for ; Sat, 31 Oct 2015 19:47:01 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from hz.grosbein.net (hz.grosbein.net [78.47.246.247]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client CN "hz.grosbein.net", Issuer "hz.grosbein.net" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id A5E801525; Sat, 31 Oct 2015 19:47:00 +0000 (UTC) (envelope-from eugen@grosbein.net) Received: from eg.sd.rdtc.ru (root@eg.sd.rdtc.ru [62.231.161.221]) by hz.grosbein.net (8.14.9/8.14.9) with ESMTP id t9VJkptu051463 (version=TLSv1/SSLv3 cipher=DHE-RSA-AES256-SHA bits=256 verify=NOT); Sat, 31 Oct 2015 20:46:52 +0100 (CET) (envelope-from eugen@grosbein.net) X-Envelope-From: eugen@grosbein.net X-Envelope-To: adrian@freebsd.org Received: from eg.sd.rdtc.ru (eugen@localhost [127.0.0.1]) by eg.sd.rdtc.ru (8.15.2/8.15.2) with ESMTP id t9VJkkX0052282; Sun, 1 Nov 2015 02:46:46 +0700 (KRAT) (envelope-from eugen@grosbein.net) Subject: Re: CPU underload To: Adrian Chadd References: <56348063.3090508@grosbein.net> <56348239.3050701@grosbein.net> <563500FC.8020201@grosbein.net> <5635148B.2070307@grosbein.net> Cc: "freebsd-mips@freebsd.org" From: Eugene Grosbein X-Enigmail-Draft-Status: N1110 Message-ID: <56351AA6.80903@grosbein.net> Date: Sun, 1 Nov 2015 02:46:46 +0700 User-Agent: Mozilla/5.0 (X11; FreeBSD amd64; rv:38.0) Gecko/20100101 Thunderbird/38.2.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=us-ascii Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=0.3 required=5.0 tests=BAYES_00,LOCAL_FROM, T_DATE_IN_FUTURE_96_Q autolearn=no version=3.3.2 X-Spam-Report: * 0.0 T_DATE_IN_FUTURE_96_Q Date: is 4 days to 4 months after Received: * date * -2.3 BAYES_00 BODY: Bayes spam probability is 0 to 1% * [score: 0.0000] * 2.6 LOCAL_FROM From my domains X-Spam-Checker-Version: SpamAssassin 3.3.2 (2011-06-06) on hz.grosbein.net X-BeenThere: freebsd-mips@freebsd.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: Porting FreeBSD to MIPS List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 31 Oct 2015 19:47:01 -0000 On 01.11.2015 02:24, Adrian Chadd wrote: > OK, so those messages are expected when you run hwpmc. Sigh, I should > just rate limit that message and make it a counter. (I had to comment > it out here.) > > Do you get those unaligned fixup messages when you're not running > hwpmc? No. > During the test, what's the latency between your two test boxes? Try a > ping from FTP client->server and see. It takes 20 seconds now to transfer 1GB file over FTP. "ping -c 150 -s 1472 -i 0.1" during the test results in: 150 packets transmitted, 150 packets received, 0.0% packet loss round-trip min/avg/max/stddev = 0.250/0.735/7.362/0.775 ms And with idle network it shows pretty same: 150 packets transmitted, 150 packets received, 0.0% packet loss round-trip min/avg/max/stddev = 0.252/0.753/6.927/1.538 ms Maximum delay is pretty hight and that bothers me. Here is the output without -q flag. Note that high delay occured for packets number 35, 45, 55, 65, 105. Script started on Sun Nov 1 02:38:05 2015 command: ping -c 150 -s 1472 -i 0.1 192.168.3.1 PING 192.168.3.1 (192.168.3.1): 1472 data bytes 1480 bytes from 192.168.3.1: icmp_seq=0 ttl=64 time=0.307 ms 1480 bytes from 192.168.3.1: icmp_seq=1 ttl=64 time=0.692 ms 1480 bytes from 192.168.3.1: icmp_seq=2 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=3 ttl=64 time=0.268 ms 1480 bytes from 192.168.3.1: icmp_seq=4 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=5 ttl=64 time=0.283 ms 1480 bytes from 192.168.3.1: icmp_seq=6 ttl=64 time=0.285 ms 1480 bytes from 192.168.3.1: icmp_seq=7 ttl=64 time=0.270 ms 1480 bytes from 192.168.3.1: icmp_seq=8 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=9 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=10 ttl=64 time=0.290 ms 1480 bytes from 192.168.3.1: icmp_seq=11 ttl=64 time=0.693 ms 1480 bytes from 192.168.3.1: icmp_seq=12 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=13 ttl=64 time=0.277 ms 1480 bytes from 192.168.3.1: icmp_seq=14 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=15 ttl=64 time=0.296 ms 1480 bytes from 192.168.3.1: icmp_seq=16 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=17 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=18 ttl=64 time=0.270 ms 1480 bytes from 192.168.3.1: icmp_seq=19 ttl=64 time=0.276 ms 1480 bytes from 192.168.3.1: icmp_seq=20 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=21 ttl=64 time=0.697 ms 1480 bytes from 192.168.3.1: icmp_seq=22 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=23 ttl=64 time=0.271 ms 1480 bytes from 192.168.3.1: icmp_seq=24 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=25 ttl=64 time=0.320 ms 1480 bytes from 192.168.3.1: icmp_seq=26 ttl=64 time=0.275 ms 1480 bytes from 192.168.3.1: icmp_seq=27 ttl=64 time=0.268 ms 1480 bytes from 192.168.3.1: icmp_seq=28 ttl=64 time=0.258 ms 1480 bytes from 192.168.3.1: icmp_seq=29 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=30 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=31 ttl=64 time=0.689 ms 1480 bytes from 192.168.3.1: icmp_seq=32 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=33 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=34 ttl=64 time=0.257 ms 1480 bytes from 192.168.3.1: icmp_seq=35 ttl=64 time=6.195 ms 1480 bytes from 192.168.3.1: icmp_seq=36 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=37 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=38 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=39 ttl=64 time=0.345 ms 1480 bytes from 192.168.3.1: icmp_seq=40 ttl=64 time=0.270 ms 1480 bytes from 192.168.3.1: icmp_seq=41 ttl=64 time=0.690 ms 1480 bytes from 192.168.3.1: icmp_seq=42 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=43 ttl=64 time=0.271 ms 1480 bytes from 192.168.3.1: icmp_seq=44 ttl=64 time=0.330 ms 1480 bytes from 192.168.3.1: icmp_seq=45 ttl=64 time=6.913 ms 1480 bytes from 192.168.3.1: icmp_seq=46 ttl=64 time=0.293 ms 1480 bytes from 192.168.3.1: icmp_seq=47 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=48 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=49 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=50 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=51 ttl=64 time=0.690 ms 1480 bytes from 192.168.3.1: icmp_seq=52 ttl=64 time=0.282 ms 1480 bytes from 192.168.3.1: icmp_seq=53 ttl=64 time=0.268 ms 1480 bytes from 192.168.3.1: icmp_seq=54 ttl=64 time=0.256 ms 1480 bytes from 192.168.3.1: icmp_seq=55 ttl=64 time=6.875 ms 1480 bytes from 192.168.3.1: icmp_seq=56 ttl=64 time=0.307 ms 1480 bytes from 192.168.3.1: icmp_seq=57 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=58 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=59 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=60 ttl=64 time=0.277 ms 1480 bytes from 192.168.3.1: icmp_seq=61 ttl=64 time=0.693 ms 1480 bytes from 192.168.3.1: icmp_seq=62 ttl=64 time=0.281 ms 1480 bytes from 192.168.3.1: icmp_seq=63 ttl=64 time=0.268 ms 1480 bytes from 192.168.3.1: icmp_seq=64 ttl=64 time=0.257 ms 1480 bytes from 192.168.3.1: icmp_seq=65 ttl=64 time=6.877 ms 1480 bytes from 192.168.3.1: icmp_seq=66 ttl=64 time=0.281 ms 1480 bytes from 192.168.3.1: icmp_seq=67 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=68 ttl=64 time=0.281 ms 1480 bytes from 192.168.3.1: icmp_seq=69 ttl=64 time=0.269 ms 1480 bytes from 192.168.3.1: icmp_seq=70 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=71 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=72 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=73 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=74 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=75 ttl=64 time=0.280 ms 1480 bytes from 192.168.3.1: icmp_seq=76 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=77 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=78 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=79 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=80 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=81 ttl=64 time=0.684 ms 1480 bytes from 192.168.3.1: icmp_seq=82 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=83 ttl=64 time=0.318 ms 1480 bytes from 192.168.3.1: icmp_seq=84 ttl=64 time=0.287 ms 1480 bytes from 192.168.3.1: icmp_seq=85 ttl=64 time=0.277 ms 1480 bytes from 192.168.3.1: icmp_seq=86 ttl=64 time=0.260 ms 1480 bytes from 192.168.3.1: icmp_seq=87 ttl=64 time=0.269 ms 1480 bytes from 192.168.3.1: icmp_seq=88 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=89 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=90 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=91 ttl=64 time=0.689 ms 1480 bytes from 192.168.3.1: icmp_seq=92 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=93 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=94 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=95 ttl=64 time=0.277 ms 1480 bytes from 192.168.3.1: icmp_seq=96 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=97 ttl=64 time=0.296 ms 1480 bytes from 192.168.3.1: icmp_seq=98 ttl=64 time=0.282 ms 1480 bytes from 192.168.3.1: icmp_seq=99 ttl=64 time=0.269 ms 1480 bytes from 192.168.3.1: icmp_seq=100 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=101 ttl=64 time=0.691 ms 1480 bytes from 192.168.3.1: icmp_seq=102 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=103 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=104 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=105 ttl=64 time=6.101 ms 1480 bytes from 192.168.3.1: icmp_seq=106 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=107 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=108 ttl=64 time=0.259 ms 1480 bytes from 192.168.3.1: icmp_seq=109 ttl=64 time=0.271 ms 1480 bytes from 192.168.3.1: icmp_seq=110 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=111 ttl=64 time=0.691 ms 1480 bytes from 192.168.3.1: icmp_seq=112 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=113 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=114 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=115 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=116 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=117 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=118 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=119 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=120 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=121 ttl=64 time=0.271 ms 1480 bytes from 192.168.3.1: icmp_seq=122 ttl=64 time=0.277 ms 1480 bytes from 192.168.3.1: icmp_seq=123 ttl=64 time=0.268 ms 1480 bytes from 192.168.3.1: icmp_seq=124 ttl=64 time=0.262 ms 1480 bytes from 192.168.3.1: icmp_seq=125 ttl=64 time=0.279 ms 1480 bytes from 192.168.3.1: icmp_seq=126 ttl=64 time=0.289 ms 1480 bytes from 192.168.3.1: icmp_seq=127 ttl=64 time=0.269 ms 1480 bytes from 192.168.3.1: icmp_seq=128 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=129 ttl=64 time=0.265 ms 1480 bytes from 192.168.3.1: icmp_seq=130 ttl=64 time=0.263 ms 1480 bytes from 192.168.3.1: icmp_seq=131 ttl=64 time=0.257 ms 1480 bytes from 192.168.3.1: icmp_seq=132 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=133 ttl=64 time=0.266 ms 1480 bytes from 192.168.3.1: icmp_seq=134 ttl=64 time=0.260 ms 1480 bytes from 192.168.3.1: icmp_seq=135 ttl=64 time=2.064 ms 1480 bytes from 192.168.3.1: icmp_seq=136 ttl=64 time=0.273 ms 1480 bytes from 192.168.3.1: icmp_seq=137 ttl=64 time=0.270 ms 1480 bytes from 192.168.3.1: icmp_seq=138 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=139 ttl=64 time=0.267 ms 1480 bytes from 192.168.3.1: icmp_seq=140 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=141 ttl=64 time=0.685 ms 1480 bytes from 192.168.3.1: icmp_seq=142 ttl=64 time=0.261 ms 1480 bytes from 192.168.3.1: icmp_seq=143 ttl=64 time=0.264 ms 1480 bytes from 192.168.3.1: icmp_seq=144 ttl=64 time=0.257 ms 1480 bytes from 192.168.3.1: icmp_seq=145 ttl=64 time=0.274 ms 1480 bytes from 192.168.3.1: icmp_seq=146 ttl=64 time=0.257 ms 1480 bytes from 192.168.3.1: icmp_seq=147 ttl=64 time=0.270 ms 1480 bytes from 192.168.3.1: icmp_seq=148 ttl=64 time=0.255 ms 1480 bytes from 192.168.3.1: icmp_seq=149 ttl=64 time=0.264 ms --- 192.168.3.1 ping statistics --- 150 packets transmitted, 150 packets received, 0.0% packet loss round-trip min/avg/max/stddev = 0.255/0.527/6.913/1.143 ms First I've supposed its some bridge's STP timer firing up but disabling STP does not help, same periodic delays.