From owner-freebsd-arm@freebsd.org Fri Jun 22 02:29:01 2018 Return-Path: Delivered-To: freebsd-arm@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 2265B100AB46 for ; Fri, 22 Jun 2018 02:29:01 +0000 (UTC) (envelope-from marklmi@yahoo.com) Received: from sonic303-20.consmr.mail.ne1.yahoo.com (sonic303-20.consmr.mail.ne1.yahoo.com [66.163.188.146]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 9253B79ED7 for ; Fri, 22 Jun 2018 02:29:00 +0000 (UTC) (envelope-from marklmi@yahoo.com) X-YMail-OSG: 7sbMD7EVM1mlOL79P13a2P7yqHZtBdLMwbVfDsJMfupgXJSr3VhZdIy1efHqx54 jiNxENmkQEjrh8YhA2pDfix5JyyUysM9aCOcYQyEc2LfKfrlLC6wGb404z_eHRTwCOhN0dPjf72F plZaZAUYacHRE2qKC_aidtVU5WA6ckz4nRbbHd5eGfY0eFTtVfTDluSXoqbWr_tKZBhgGTt9.zW_ haZ9AoVjzEQDDOllG8ugX4XeNHp6W.ySlSD8jmQh9Ny.JAACfqHczvh.dS5Qrf063B941olQy_DW bjzMygsxjfIzmn_nph4oErTdS_3e30cef9oVkzGf1GwxLMfb1cZK96RrZPetsW70vfTE..6YwB4F HE_JJAfHISfO1.XJp5z5vIvMkhVxw7lUBejXXDMp0e.qKg60oXQ6Jj74FSZ6y5Z3AQ9AMO6LYEOm MTuZE8v3oB.k_ql33F9ODpKBanGlNL9dZnhRsfsocpE7RgoJfcO3GqDQJ_PDsoA5XOMHUqpcLHGP oH3i_46aspDNn1on6OeJKFMVm1GMr34dtGfDHB5QE5nYgirll0Tb8WbsdKS0Ha746m4cwbCqa2ax mizEj7qm__yUaRbFnHlAUa_TVeLZ7Va4EZtaHg8D.VvBBteIEup8CN5DGfMphVrWgv4aRTCGQc8n 54AAKgIUCL6ub4T0Ivanere9BGxYGMZW8rJF0rYCR9nPLQypPWJtWiAaea_ca5lAG7ihBe5RK.i4 ALhYIqociOtlSDL0dQLnenS19ezzrGzvrzMJzLWSC4DdGhic_RvreJcOTjpHtWGWPtvgOEGJIGgo NZkEnOTIKqJjhq7VTKk0Q3Yx_cdkBnQHsf_Gm7Kdob0s1_8_pVK0l2gajbeIPfRYX4bKWRUYCZ6d Ewg_fbCYBg6CeQLovPmWbnJ_PhEXP2AWInEPmIu9Rsx9k6HapY8uAwNrqtQcbys60QRKy6.5.6Ly 6Zd3YeHeRbfIB2eaGoVOOPQwzGEmP Received: from sonic.gate.mail.ne1.yahoo.com by sonic303.consmr.mail.ne1.yahoo.com with HTTP; Fri, 22 Jun 2018 02:28:53 +0000 Received: from ip70-189-131-151.lv.lv.cox.net (EHLO [192.168.0.105]) ([70.189.131.151]) by smtp432.mail.ne1.yahoo.com (Oath Hermes SMTP Server) with ESMTPA ID 5e3d057d192a4d935ad9fec89f9404b3; Fri, 22 Jun 2018 02:28:48 +0000 (UTC) Content-Type: text/plain; charset=us-ascii Mime-Version: 1.0 (Mac OS X Mail 11.4 \(3445.8.2\)) Subject: Re: GPT vs MBR for swap devices From: Mark Millard In-Reply-To: <20180622010911.GA98112@www.zefox.net> Date: Thu, 21 Jun 2018 19:28:45 -0700 Cc: Trev , freebsd-arm Content-Transfer-Encoding: quoted-printable Message-Id: <73352F3D-75B9-4509-9F96-0B4559375977@yahoo.com> References: <25F1A4BA-FBFC-4C32-85DD-5F5BA71A2B1A@yahoo.com> <20180620023253.GA89924@www.zefox.net> <1D86911D-20D1-494A-822B-1C07C5598CB1@yahoo.com> <20180622010911.GA98112@www.zefox.net> To: bob prohaska X-Mailer: Apple Mail (2.3445.8.2) X-BeenThere: freebsd-arm@freebsd.org X-Mailman-Version: 2.1.26 Precedence: list List-Id: "Porting FreeBSD to ARM processors." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Fri, 22 Jun 2018 02:29:01 -0000 On 2018-Jun-21, at 6:09 PM, bob prohaska wrote: > On Thu, Jun 21, 2018 at 07:16:19AM -0700, Mark Millard wrote: >>=20 >>=20 >>=20 >> It looks like the latest from Bob P. is that when his /dev/da0 >> is not used for swap (and so has far less I/O) his builds finish, >> apparently without logging errors: >>=20 >>=20 > A little more testing has been completed.=20 >=20 > With enough swap not on da0 -j4 buildworld finishes. It does not seem = to=20 > matter what the swap is on: SD flash, USB flash or USB mechanical. = With=20 > any swap on da0 -j4 buildworld does not finish because of intervention > by OOMA (the out of memory assassin). Occasionally, OOMA runs amok, > killing processes not obviously consuming lots of memory.=20 >=20 > With not enough swap not on da0 the result is somewhat surprising.=20 >=20 > In three trials of using 1 GB of swap on the SD card, the machine = reported it was out > of swap, the OOM assassin did not come to the rescue and eventually = the machine > stalled. The log files of gstat and swapinfo data are at > = http://www.zefox.net/~fbsd/rpi3/swaptests/newtests/1gbsdflash_swapinfo/1gb= sdflash_swapinfo.log > = http://www.zefox.net/~fbsd/rpi3/swaptests/newtests/1gbsdflash_swapinfo/new= test/2nd1gbsdflash_swapinfo.log > and > = http://www.zefox.net/~fbsd/rpi3/swaptests/newtests/1gbsdflash_swapinfo/new= test/3rdtest/3rd1gbsdflash_swapinfo.log >=20 > Each directory also holds what I could gather from the console and = buildworld. >=20 > The errors on the console seem to suggest a loss of communication with = da0. Could=20 > something like usbdump be used to shed more light on what's going on?=20= I'm afraid that tracking things down to USB protocol level traces is outside the range I'm familiar with (other than with a logic analyzer with USB support). I'll note that in 2nd1gbsdflash_swapinfo.log I see more examples of large ms/w figures (and ms/r) for /dev/da0 (and some of its partitions). For example: dT: 10.071s w: 10.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps = ms/d %busy Name 0 4 4 61 1.5 0 7 5.8 0 0 = 0.0 0.7 mmcsd0 8 1 0 3 27995 1 20 25706 0 0 = 0.0 275.9 da0 0 0 0 0 0.0 0 7 5.9 0 0 = 0.0 0.1 mmcsd0s2 0 4 4 61 1.5 0 0 0.0 0 0 = 0.0 0.6 mmcsd0s3 0 0 0 0 0.0 0 7 5.9 0 0 = 0.0 0.1 ufs/rootfs 0 4 4 61 1.5 0 0 0.0 0 0 = 0.0 0.6 mmcsd0s3b 4 0 0 0 0.0 0 7 27710 0 0 = 0.0 277.9 da0a 4 1 0 3 27996 1 14 24370 0 0 = 0.0 275.8 da0d The console.log for that run showed: swap_pager_getswapspace(17): failed swap_pager_getswapspace(32): failed swap_pager_getswapspace(24): failed swap_pager_getswapspace(18): failed swap_pager_getswapspace(32): failed swap_pager_getswapspace(24): failed swap_pager_getswapspace(18): failed swap_pager_getswapspace(13): failed (da0:umass-sim0:0:0:0): WRITE(10). CDB: 2a 00 00 18 02 00 00 00 40 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error swap_pager_getswapspace(23): failed (da0:umass-sim0:0:0:0): Retrying command, 2 more tries remain swap_pager_getswapspace(12): failed swap_pager_getswapspace(13): failed few minute delay wap_pager_getswapspace(19): failed swap_pager_getswapspace(12): failed swap_pager_getswapspace(9): failed (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 10 01 80 00 00 20 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Retrying command, 2 more tries remain (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 10 01 80 00 00 20 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Retrying command, 1 more tries remain (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 10 01 80 00 00 20 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Retrying command, 0 more tries remain (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 10 01 80 00 00 20 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Error 5, Retries exhausted g_vfs_done():da0a[WRITE(offset=3D827523072, length=3D32768)]error =3D 5 g_vfs_done():da0a[WRITE(offset=3D830046208, length=3D32768)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D65536, length=3D4096)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D20709376, length=3D4096)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D51207667712, length=3D32768)]error =3D = 5 g_vfs_done():da0d[WRITE(offset=3D51207864320, length=3D32768)]error =3D = 5 g_vfs_done():da0d[WRITE(offset=3D51207962624, length=3D32768)]error =3D = 5 g_vfs_done():da0d[WRITE(offset=3D51228348416, length=3D4096)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D51650527232, length=3D32768)]error =3D = 5 g_vfs_done():da0a[WRITE(offset=3D277078016, length=3D4096)]error =3D 5 g_vfs_done():da0a[READ(offset=3D537067520, length=3D16384)]error =3D 5 (da0:umass-sim0:0:0:0): WRITE(10). CDB: 2a 00 00 40 9e 00 00 00 08 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Retrying command, 3 more tries remain (End of "showed".) So it appears that swap activity on /dev/da0 is not required in order to have the problems on /dev/da0 . I suspect that with a drive that does not have the above problems, the OOM process might have handled the out-of-swap without hanging up. (Or at least had a better chance of doing so.) For: = http://www.zefox.net/~fbsd/rpi3/swaptests/newtests/1gbsdflash_swapinfo/new= test/3rdtest/3rd1gbsdflash_swapinfo.log using grep I find some large (>9999) figures for da0 (or its = partitions). (The grep is lucky because large figures in other columns could be matched.) $ grep "[0-9][0-9][0-9][0-9][0-9].*da0" = /Users/markmi/Downloads/3rd1gbsdflash_swapinfo.log.txt | more 45 2 0 0 0.0 2 116 11360 0 0 = 0.0 104.9 da0 40 1 0 0 0.0 1 110 11343 0 0 = 0.0 104.5 da0d 40 3 0 4 15306 2 79 11040 0 0 = 0.0 102.4 da0 35 3 0 4 15306 2 85 10481 0 0 = 0.0 102.9 da0d 0 0 0 0 0.0 0 3 10843 0 0 = 0.0 108.4 da0a for which the first 4 with ms/r or ms/w being large are in: Thu Jun 21 07:42:19 PDT 2018 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s3b 1048576 0 1048576 0% dT: 10.211s w: 10.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps = ms/d %busy Name 0 0 0 0 0.0 0 7 6.9 0 0 = 0.0 0.1 mmcsd0 45 2 0 0 0.0 2 116 11360 0 0 = 0.0 104.9 da0 40 1 0 0 0.0 1 110 11343 0 0 = 0.0 104.5 da0d Thu Jun 21 07:42:29 PDT 2018 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s3b 1048576 0 1048576 0% dT: 10.019s w: 10.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps = ms/d %busy Name 40 3 0 4 15306 2 79 11040 0 0 = 0.0 102.4 da0 35 3 0 4 15306 2 85 10481 0 0 = 0.0 102.9 da0d Thu Jun 21 07:42:39 PDT 2018 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s3b 1048576 0 1048576 0% and the last (large ms/w) is in: Thu Jun 21 14:23:04 PDT 2018 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s3b 1048576 55100 993476 5% dT: 10.003s w: 10.000s L(q) ops/s r/s kBps ms/r w/s kBps ms/w d/s kBps = ms/d %busy Name 0 0 0 0 0.0 0 15 19.6 0 0 = 0.0 0.5 mmcsd0 23 91 43 1382 46.5 48 3052 601.3 0 0 = 0.0 99.2 da0 0 0 0 0 0.0 0 3 12.5 0 0 = 0.0 0.1 mmcsd0s2 0 0 0 0 0.0 0 12 21.5 0 0 = 0.0 0.3 mmcsd0s3 0 0 0 0 0.0 0 3 12.5 0 0 = 0.0 0.1 ufs/rootfs 0 0 0 0 0.0 0 12 21.5 0 0 = 0.0 0.3 mmcsd0s3a 0 0 0 0 0.0 0 3 10843 0 0 = 0.0 108.4 da0a 12 67 43 1382 46.6 24 3049 656.4 0 0 = 0.0 115.4 da0d Thu Jun 21 14:23:14 PDT 2018 Device 1K-blocks Used Avail Capacity /dev/mmcsd0s3b 1048576 55100 993476 5% I do not find >9999 for mmc*'s for ms/w or ms/r in that file. The console had: swap_pager_getswapspace(14): failed swap_pager_getswapspace(11): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(13): failed swap_pager_getswapspace(10): failed (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 18 bb c0 00 00 40 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Retrying command, 0 more tries remain swap_pager_getswapspace(7): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(7): failed swap_pager_getswapspace(9): failed swap_pager_getswapspace(8): failed swap_pager_getswapspace(8): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(9): failed swap_pager_getswapspace(8): failed swap_pager_getswapspace(24): failed swap_pager_getswapspace(18): failed swap_pager_getswapspace(14): failed swap_pager_getswapspace(11): failed swap_pager_getswapspace(6): failed swap_pager_getswapspace(7): failed swap_pager_getswapspace(10): failed swap_pager_getswapspace(11): failed swap_pager_getswapspace(6): failed (da0:umass-sim0:0:0:0): READ(10). CDB: 28 00 00 18 bb c0 00 00 40 00=20 (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error (da0:umass-sim0:0:0:0): Error 5, Retries exhausted g_vfs_done():da0d[WRITE(offset=3D65536, length=3D4096)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D20709376, length=3D4096)]error =3D 5 g_vfs_done():da0d[READ(offset=3D17288822784, length=3D32768)]error =3D 5 g_vfs_done():vm_fault: pager read error, pid 51522 (c++) da0d[WRITE(offset=3D51207864320, length=3D32768)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D51207962624, length=3D32768)]error =3D = 5 g_vfs_done():da0d[WRITE(offset=3D51228348416, length=3D4096)]error =3D 5 g_vfs_done():da0d[WRITE(offset=3D51655704576, length=3D32768)]error =3D = 5 g_vfs_done():da0a[READ(offset=3D829915136, length=3D32768)]error =3D 5 Fatal data abort: . . . (omitted register dump) . . . [ thread pid 496 tid 100100 ] Stopped at cluster_write+0x228: ldr x9, [x8, #80]! db>=20 =3D=3D=3D Mark Millard marklmi at yahoo.com ( dsl-only.net went away in early 2018-Mar)