Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 21 Jun 2018 19:28:45 -0700
From:      Mark Millard <marklmi@yahoo.com>
To:        bob prohaska <fbsd@www.zefox.net>
Cc:        Trev <freebsd-arm@sentry.org>, freebsd-arm <freebsd-arm@freebsd.org>
Subject:   Re: GPT vs MBR for swap devices
Message-ID:  <73352F3D-75B9-4509-9F96-0B4559375977@yahoo.com>
In-Reply-To: <20180622010911.GA98112@www.zefox.net>
References:  <25F1A4BA-FBFC-4C32-85DD-5F5BA71A2B1A@yahoo.com> <20180620023253.GA89924@www.zefox.net> <a232ed45-a9a9-1017-72ed-720a6c7a8f03@sentry.org> <1D86911D-20D1-494A-822B-1C07C5598CB1@yahoo.com> <20180622010911.GA98112@www.zefox.net>

next in thread | previous in thread | raw e-mail | index | archive | help
On 2018-Jun-21, at 6:09 PM, bob prohaska <fbsd at www.zefox.net> 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)




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?73352F3D-75B9-4509-9F96-0B4559375977>