From owner-freebsd-arm@freebsd.org Tue Mar 24 15:57:55 2020 Return-Path: Delivered-To: freebsd-arm@mailman.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.nyi.freebsd.org (Postfix) with ESMTP id 999C0260934 for ; Tue, 24 Mar 2020 15:57:55 +0000 (UTC) (envelope-from fbsd@www.zefox.net) Received: from www.zefox.net (www.zefox.net [50.1.20.27]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "www.zefox.org", Issuer "www.zefox.org" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 48mwr73nbTz4NMX for ; Tue, 24 Mar 2020 15:57:41 +0000 (UTC) (envelope-from fbsd@www.zefox.net) Received: from www.zefox.net (localhost [127.0.0.1]) by www.zefox.net (8.15.2/8.15.2) with ESMTPS id 02OFvr5m092021 (version=TLSv1.2 cipher=DHE-RSA-AES256-GCM-SHA384 bits=256 verify=NO); Tue, 24 Mar 2020 08:57:54 -0700 (PDT) (envelope-from fbsd@www.zefox.net) Received: (from fbsd@localhost) by www.zefox.net (8.15.2/8.15.2/Submit) id 02OFvrab092020; Tue, 24 Mar 2020 08:57:53 -0700 (PDT) (envelope-from fbsd) Date: Tue, 24 Mar 2020 08:57:53 -0700 From: bob prohaska To: freebsd-arm@freebsd.org Subject: Belated out of swap kill on rpi3 at r359216 Message-ID: <20200324155753.GA91922@www.zefox.net> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.24 (2015-08-30) X-Rspamd-Queue-Id: 48mwr73nbTz4NMX X-Spamd-Bar: ++ Authentication-Results: mx1.freebsd.org; dkim=none; dmarc=none; spf=none (mx1.freebsd.org: domain of fbsd@www.zefox.net has no SPF policy when checking 50.1.20.27) smtp.mailfrom=fbsd@www.zefox.net X-Spamd-Result: default: False [2.85 / 15.00]; ARC_NA(0.00)[]; WWW_DOT_DOMAIN(0.50)[]; RCVD_TLS_ALL(0.00)[]; FROM_HAS_DN(0.00)[]; TO_DN_SOME(0.00)[]; IP_SCORE(0.06)[ip: (0.24), ipnet: 50.1.16.0/20(0.12), asn: 7065(-0.03), country: US(-0.05)]; MIME_GOOD(-0.10)[text/plain]; DMARC_NA(0.00)[zefox.net]; AUTH_NA(1.00)[]; NEURAL_SPAM_MEDIUM(0.24)[0.244,0]; TO_MATCH_ENVRCPT_SOME(0.00)[]; RCPT_COUNT_TWO(0.00)[2]; NEURAL_SPAM_LONG(0.65)[0.652,0]; R_SPF_NA(0.00)[]; FROM_EQ_ENVFROM(0.00)[]; R_DKIM_NA(0.00)[]; MIME_TRACE(0.00)[0:+]; ASN(0.00)[asn:7065, ipnet:50.1.16.0/20, country:US]; MID_RHS_MATCH_FROM(0.00)[]; MID_RHS_WWW(0.50)[]; RCVD_COUNT_TWO(0.00)[2] X-BeenThere: freebsd-arm@freebsd.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: "Porting FreeBSD to ARM processors." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 24 Mar 2020 15:57:55 -0000 An attempt to buildworld on an rpi3 running r359216 stopped with an OOMA kill. Sources were at 359264, loader.conf contained vm.pageout_oom_seq="4096" . A snipped of gstat log suggests the worst congestion in the storage I/O happened at Tue Mar 24 04:52:26 PDT 2020 with an L(q) of 37, but the OOMA kill happened at Tue Mar 24 04:53:04 PDT 2020, by which time the L(q) had dropped to one, half a minute later. Is the delay in OOMA action to be expected? Here's the relevant part of the log, I hope the columns display readably: 0/2/2/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 0 0 29 1897320 47312 12851 9 4 5 13330 1669 0 0 14172 8020 3034 65 29 6 dT: 1.056s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 37 367 323 5463 6.4 45 1511 76.8 0 0 0.0 91.7 mmcsd0 37 367 323 5463 6.5 45 1511 76.9 0 0 0.0 93.3 mmcsd0s2 34 133 111 3209 7.6 22 697 134.7 0 0 0.0 74.0 mmcsd0s2a 3 235 212 2254 5.9 23 814 21.5 0 0 0.0 70.0 mmcsd0s2b 34 133 111 3209 7.6 22 697 134.7 0 0 0.0 74.2 ufs/rootfs Tue Mar 24 04:52:26 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 224484 4179768 5% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 0/0/0/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 3 0 29 1936132 19232 12849 9 4 5 13328 1671 0 0 14173 8020 3036 65 29 6 dT: 1.010s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 9 323 148 2531 20.7 175 3327 14.6 0 0 0.0 97.2 mmcsd0 9 323 148 2531 20.8 175 3327 14.6 0 0 0.0 98.4 mmcsd0s2 2 96 96 1869 16.9 0 0 0.0 0 0 0.0 82.9 mmcsd0s2a 7 227 51 661 28.3 175 3327 14.6 0 0 0.0 84.0 mmcsd0s2b 2 96 96 1869 16.9 0 0 0.0 0 0 0.0 83.0 ufs/rootfs Tue Mar 24 04:52:41 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 272928 4131324 6% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 0/0/0/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 0 0 29 1939940 48016 12849 9 4 5 13328 1676 948 0 14174 8019 3037 65 29 6 dT: 1.001s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 3 371 151 1989 91.0 221 3847 14.0 0 0 0.0 100.1 mmcsd0 3 371 151 1989 91.1 221 3847 14.0 0 0 0.0 100.1 mmcsd0s2 1 41 41 415 74.5 0 0 0.0 0 0 0.0 304.8 mmcsd0s2a 2 331 110 1574 97.3 221 3847 14.0 0 0 0.0 99.3 mmcsd0s2b 1 41 41 415 74.5 0 0 0.0 0 0 0.0 304.9 ufs/rootfs Tue Mar 24 04:52:45 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 282480 4121772 6% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 0/2/2/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 2 0 29 1944652 42768 12849 9 4 5 13328 1678 0 0 14174 8019 3037 65 29 6 dT: 1.010s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 2 498 498 6345 3.5 0 0 0.0 0 0 0.0 88.8 mmcsd0 2 498 498 6345 3.9 0 0 0.0 0 0 0.0 98.3 mmcsd0s2 1 152 152 1501 4.1 0 0 0.0 0 0 0.0 62.1 mmcsd0s2a 1 346 346 4844 3.9 0 0 0.0 0 0 0.0 88.8 mmcsd0s2b 1 152 152 1501 4.2 0 0 0.0 0 0 0.0 62.5 ufs/rootfs Tue Mar 24 04:52:47 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 282396 4121856 6% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 0/0/0/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 5 0 28 1980200 19676 12848 9 4 5 13327 1684 714 0 14175 8019 3039 65 29 6 dT: 1.002s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 9 487 174 1449 26.2 313 2427 9.1 0 0 0.0 98.4 mmcsd0 9 487 174 1449 26.4 313 2427 9.1 0 0 0.0 100.0 mmcsd0s2 1 45 45 267 22.9 0 0 0.0 0 0 0.0 80.3 mmcsd0s2a 9 442 129 1182 27.7 313 2427 9.1 0 0 0.0 97.2 mmcsd0s2b 1 45 45 267 22.9 0 0 0.0 0 0 0.0 80.4 ufs/rootfs Tue Mar 24 04:53:01 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 309996 4094256 7% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 0/2/2/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 0 0 29 1983636 44400 12848 9 4 5 13326 1689 0 0 14175 8018 3040 65 29 6 dT: 1.002s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 12 528 0 0 0.0 528 3797 7.5 0 0 0.0 100.0 mmcsd0 12 528 0 0 0.0 528 3797 7.5 0 0 0.0 100.0 mmcsd0s2 11 528 0 0 0.0 528 3797 7.5 0 0 0.0 100.0 mmcsd0s2b Tue Mar 24 04:53:05 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 322360 4081892 7% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 21842, size: 12288 Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 3/769/772/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 1 0 29 1826272 165204 12848 9 4 5 13326 1689 971 0 14176 8018 3040 65 29 6 dT: 1.001s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 1 614 604 4661 4.9 10 168 40.6 0 0 0.0 93.8 mmcsd0 1 614 604 4661 4.9 10 168 40.6 0 0 0.0 94.5 mmcsd0s2 0 210 209 1243 4.1 1 32 181.0 0 0 0.0 83.1 mmcsd0s2a 1 404 395 3418 5.4 9 136 25.1 0 0 0.0 81.0 mmcsd0s2b 0 210 209 1243 4.1 1 32 181.0 0 0 0.0 83.6 ufs/rootfs Tue Mar 24 04:53:08 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 230064 4174188 5% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 Mar 24 04:53:04 www kernel: pid 96708 (c++), jid 0, uid 0, was killed: out of swap space 0/772/772/19177 mbuf clusters in use (current/cache/total/max) procs memory page disks faults cpu r b w avm fre flt re pi po fr sr mm0 da0 in sy cs us sy id 2 0 28 1705884 221144 12848 9 4 5 13326 1689 1109 0 14176 8018 3041 65 29 6 dT: 1.002s w: 1.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps ms/d %busy Name 0 545 545 3580 2.1 0 0 0.0 0 0 0.0 74.0 mmcsd0 0 545 545 3580 2.1 0 0 0.0 0 0 0.0 75.7 mmcsd0s2 0 288 288 1517 2.0 0 0 0.0 0 0 0.0 56.4 mmcsd0s2a 0 256 256 2064 2.4 0 0 0.0 0 0 0.0 49.0 mmcsd0s2b 0 288 288 1517 2.0 0 0 0.0 0 0 0.0 57.1 ufs/rootfs Tue Mar 24 04:53:10 PDT 2020 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s2b 4404252 230064 4174188 5% Mar 24 04:20:50 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 25477, size: 4096 Mar 24 04:53:04 www kernel: pid 96708 (c++), jid 0, uid 0, was killed: out of swap space [end of excerpt] Thanks for looking! bob prohaska