Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 28 Jun 2018 09:33:29 -0700
From:      bob prohaska <fbsd@www.zefox.net>
To:        Mark Millard <marklmi@yahoo.com>
Cc:        freebsd-arm@freebsd.org, bob prohaska <fbsd@www.zefox.net>
Subject:   Re: RPI3 swap experiments
Message-ID:  <20180628163328.GA33408@www.zefox.net>
In-Reply-To: <7B9D272D-3EDE-46FA-8A1C-AEE65047167C@yahoo.com>
References:  <20180626151843.GD17293@www.zefox.net> <3525D7C7-F848-45A1-BD85-2DAC895DF48C@yahoo.com> <20180626222834.GA20270@www.zefox.net> <28012DFB-37A0-461A-BB62-CD3EE61E82F0@yahoo.com> <20180627054027.GA22144@www.zefox.net> <CC72E766-03CB-476C-8F2B-DAAC266CE63D@yahoo.com> <20180627194217.GA27793@www.zefox.net> <C6303FC5-B412-472C-98E4-9A1E45C38535@yahoo.com> <20180628022457.GA30110@www.zefox.net> <7B9D272D-3EDE-46FA-8A1C-AEE65047167C@yahoo.com>

next in thread | previous in thread | raw e-mail | index | archive | help
It turns out that Peter Holm's stress2 suite will trigger a crash whose console
messages look superficially like those produced by -j4 buildworld.

The storage configuration is the same: /var and /usr on USB flash, 1 GB swap on microSD.

The gstat/swapinfo log file is at
http://www.zefox.net/~fbsd/rpi3/swaptests/r335655/1gbsdflash/stress2/swapuse.log

An early sign of trouble is

dT: 10.042s  w: 10.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
   16     57      0      0    0.0     57   6351  237.6      0      0    0.0  100.2  mmcsd0
   15     57      0      0    0.0     57   6351  237.6      0      0    0.0  100.2  mmcsd0s3
   14     57      0      0    0.0     57   6351  237.7      0      0    0.0  100.2  mmcsd0s3a
Thu Jun 28 00:52:49 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    32320  1016256     3%
Jun 28 00:52:05 www bob[2122]: Starting test df.cfg
Jun 28 00:52:45 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 3467, size: 4096
dT: 10.004s  w: 10.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
   19     51      0      0    0.0     51   5796  239.5      0      0    0.0  100.2  mmcsd0
   17     51      0      0    0.0     51   5796  239.5      0      0    0.0  100.2  mmcsd0s3
   17     51      0      0    0.0     51   5796  239.6      0      0    0.0  100.2  mmcsd0s3a
Thu Jun 28 00:52:59 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    32320  1016256     3%
Jun 28 00:52:05 www bob[2122]: Starting test df.cfg
Jun 28 00:52:45 www kernel: swap_pager: indefinite wait buffer: bufobj: 0, blkno: 3467, size: 4096

Here's the spot where the /dev/da0 errors begin in the gstat/swapinfo log:


dT: 10.002s  w: 10.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    4      9      1      3  131.4      9    186   46.9      0      0    0.0   28.5  mmcsd0
    1      1      0      0    0.0      1     34   51.6      0      0    0.0    7.2  da0
    4      9      1      3  133.3      9    186   53.3      0      0    0.0   32.9  mmcsd0s3
    3      9      0      0    0.0      9    186   53.3      0      0    0.0   32.9  mmcsd0s3a
    1      1      1      3  133.3      0      0    0.0      0      0    0.0    8.0  mmcsd0s3b
    1      1      0      0    0.0      1     34   51.7      0      0    0.0    7.2  da0a
Thu Jun 28 02:34:11 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    37736  1010840     4%
Jun 28 02:35:15 www kernel: (da0:umass-sim0:0:0:0): Error 5, Retries exhausted
Jun 28 02:35:15 www kernel: g_vfs_done():da0a[WRITE(offset=827129856, length=16384)]error = 5
dT: 10.002s  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     38     38    452  285.2      0      0    0.0      0      0    0.0   35.3  mmcsd0
    0     38     38    456  286.1      0      0    0.0      0      0    0.0   35.5  mmcsd0s3
    0     38     38    456  286.3      0      0    0.0      0      0    0.0   35.5  mmcsd0s3b
Thu Jun 28 02:40:26 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    58408   990168     6%
Jun 28 02:40:15 www kernel: (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error
Jun 28 02:40:15 www kernel: (da0:umass-sim0:0:0:0): Retrying command, 3 more tries remain
dT: 10.002s  w: 10.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
Thu Jun 28 02:40:37 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    58408   990168     6%
Jun 28 02:40:15 www kernel: (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error
Jun 28 02:40:15 www kernel: (da0:umass-sim0:0:0:0): Retrying command, 3 more tries remain
dT: 10.076s  w: 10.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
Thu Jun 28 02:40:50 PDT 2018
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s3b    1048576    58408   990168     6%
Jun 28 02:41:38 www kernel: (da0:umass-sim0:0:0:0): WRITE(10). CDB: 2a 00 00 18 a6 80 00 00 40 00 
Jun 28 02:41:38 www kernel: (da0:umass-sim0:0:0:0): CAM status: CCB request completed with an error
Jun 28 02:41:38 www kernel: (da0:umass-sim0:0:0:0): Retrying command, 1 more tries remain
Jun 28 02:41:38 www kernel: smsc0: warning: Failed to read register 0x114
Jun 28 02:41:38 www kernel: smsc0: warning: MII read timeout
[da0 error flood continues]

Curiously, the machine kept running (top output updated) until the plug was pulled next
morning.

This test is certainly quicker than using -j4 buildworld, but it isn't obvious it's
doing the same thing since /dev/da0 is exercised far less. 

Thanks for reading,

bob prohaska




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20180628163328.GA33408>