Looks Like The Is A Read/timing Problem With Sd Reading When High Cpu


Polossatik

I reject your reality and substitute my own
Joined
Oct 8, 2008
Messages
477
Location
Belgium
Website
Visit site
some idea of what is used:/dev/mmcblk0p1 is a 4gb class 6 Sd card "traveller" brand (local cheaper brand),

openpandora:/media$ sudo dd if=/dev/mmcblk0 of=/dev/null
7839744+0 records in
7839744+0 records out
4013948928 bytes (4.0 GB) copied, 233.515 s, 17.2 MB/s

now let stress the system a bit - bzip2 will use about 90% cpu

openpandora:/media$ sudo dd if=/dev/mmcblk0 |bzip2 >/dev/null
Password:
dd: reading `/dev/mmcblk0': Input/output error
57192+0 records in
57192+0 records out
29282304 bytes (29 MB) copied, 71.6724 s, 409 kB/s

same when dumping to a USB stick
openpandora:/media$ sudo dd if=/dev/mmcblk0 |bzip2 >/media/8GB_SD3/disk.dd.gz2
Password:
dd: reading `/dev/mmcblk0': Input/output error
57192+0 records in
57192+0 records out
29282304 bytes (29 MB) copied, 73.7727 s, 397 kB/s

then I tested a exact copy (same brand /model/size ) of the failing card and it also fails, but after a other amount of data:

openpandora:/media$ sudo dd if=/dev/mmcblk0 |bzip2 >/dev/null
Password:
dd: reading `/dev/mmcblk0': Input/output error
377696+0 records in
377696+0 records out
193380352 bytes (193 MB) copied, 582.049 s, 332 kB/s

It looks to me there
* is clearly a problem when reading from at least SOME Sd card's under high cpu
* it looks like card related on where it fails

it's worth noting that I tested both cards using H2testw on windows and using DD on a Ubuntu laptop , and on both systems NO fault was found.

I have other (bigger and other brands) SD cards who I let run for like a minute or 20 , but seen this is so slow I did not let them complete all the way, so I cannot be 100% sure they actually do not fail.

now I'm testing the first card again (who failed) but using the same USB cardreader as I used on my other PC's but then connected to the pandora
so far no problem found , I'll leave this test going until the whole card is dumped, but seen this is a very slow process it might take a while :)
I'll edit the post if it's done.

edit: this worked without any problems

openpandora:/media$ sudo dd if=/dev/sda |bzip2 >/dev/null
7839744+0 records in
7839744+0 records out
4013948928 bytes (4.0 GB) copied, 6230.45 s, 644 kB/s

The reason why I did this is because on that 4gb card I have put a copy of the Pandora distro and had sometimes bizarre issues.
Who looked quite random and I/O related .

I know there will be reply's like "buy a other/decent Sd card" , but the point is that at least the pandora is much more "picky" about Sd cards than other systems.
I use those cards already some time on my N800 for example and there I never had any issue that looked like SD card related.

If some people would sacrifice some CPU time on their Pandora doing the same ( sudo dd if=/dev/mmcblk0 |bzip2 >/dev/null or sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null )
to test their cards then that would be very good to see if other people have the same issue.
at the very least it might help to establish if it's only a rare/specific to certain cards occurrence or not.

If someone would have any idea of what more diagnostic info to provide , or has other idea on how to test these cards faster, please let me know.
 
So when the CPU is at high load, you see slow downs in read and right speed? Why is this surprising? Reading and writing takes some CPU power too.
Try renicing mmcqd to, like, -10 or something, see if that helps any.

edit: oooh, I completely missed the I/O errors. D'oh. I'm an idiot.
 
hehe, no, reading it back it's not so clear, I just made the I/O errors bold to avoid confusion :)
 
Polossatik said:
hehe, no, reading it back it's not so clear, I just made the I/O errors bold to avoid confusion :)
I've seen the same types of io errors as this trying to tar.bz2 up a 1Gb directory off a 16Gb Transcend class 6 SD card. Doing it on my PC had no problems.
 
Last edited by a moderator:
this is getting weirder and weirder (ok, I know the wifi also uses the SDIO interface)

I runned the same dd command (on the same sd card) run for 3600 seconds and crtl,c .
no error

next I started it agian, and after a minute I started Midori , at that this was fetching data trough wifi I got an I/O error.

this time after 58587264 bytes (so other amount of data transferred was also different from previous "runs")

so I closed Midori and starting the dd again and then started midori again - no error straight away but a few second later it failed at exact the same amount of bytes as the previous run...

then I tried a third time and no error on the dd ...

This might all be coincidence, but it's a bit to much for my liking. And all aprevious tests where also done with wifi enabled (aldo most of the time not used - no browser or so open - I did use at one point however VNC for some of the tests)

Is there any Linux guru who can actually say if an I/O error like when doing a dd on the block device itself can cause also issues on the mounted volume?
Maybe there are so many I/O retries there it simply doesn't matter? (did not tested yet on mounted volumes)

edit: ha, just saw above post.. mabe try with zipping big folders instead of dd
 
Been running for 4 hours now, no erors. Just connected with wifi, and posting from Pandora now - still OK. So it's intermittent, or card dependant.
 
I would say it's card dependent. Could be (just making wild guesses here) that there are certain blocks which are worn just enough that it takes a little bit longer to read than others. Under normal CPU load, it might have the time to retry these blocks. Under heavy CPU load, maybe it doesn't get that same retry chance, it's timing out, and just giving up. Or something along those lines. The fact that it happened twice at the same byte count is very suspicious and what makes me think it's something to do with a not-necessarily-bad-but-at-least-not-perfect block
 
Something that comes to mind is that tsh had pretty high wifi throughput as well, iirc. Maybe someone with worse wifi throughput should perform the test too. It might be related eventually.
 
I had the same issues when copying all my data across from my 16Gb card in slot 2 (Fat32) to my 32Gb card in slot 1 (SDHC). I used Thunnar but got lots of popup messages with input/output error. Would be nice if it could tell you which of the two errors it actually was!
 
Pleng said:
I had the same issues when copying all my data across from my 16Gb card in slot 2 (Fat32) to my 32Gb card in slot 1 (SDHC). I used Thunnar but got lots of popup messages with input/output error. Would be nice if it could tell you which of the two errors it actually was!

Was that with Hotfix 3 installed or before?

Before Hotfix 3, the SD Cards were mounted synced. mmcqd eats up CPU then. Should be way better with HF3 :)
 
Last edited:
ED, this is not about using to much CPU, this is about I/O errors when the CPU is stressed.

All my tests where done using the hotfix 3.
 
EvilDragon said:
Pleng said:
I had the same issues when copying all my data across from my 16Gb card in slot 2 (Fat32) to my 32Gb card in slot 1 (SDHC). I used Thunnar but got lots of popup messages with input/output error. Would be nice if it could tell you which of the two errors it actually was!

Was that with Hotfix 3 installed or before?

With

Before Hotfix 3, the SD Cards were mounted synced. mmcqd eats up CPU then. Should be way better with HF3 :)

Looks like it still needs some more work doing, then :s
 
Last edited by a moderator:
Doesn't repro for me on my cards. Maybe your card thinks it's on fire and wants to push all the data ASAP and gets upset when pandora doesn't take data fast enough? Obviously it's not a problem on PC which can pull it fast even when busy with bz2..

Polossatik said:
If someone would have any idea of what more diagnostic info to provide
dmesg output.
 
Last edited by a moderator:
notaz said:
Doesn't repro for me on my cards. Maybe your card thinks it's on fire and wants to push all the data ASAP and gets upset when pandora doesn't take data fast enough? Obviously it's not a problem on PC which can pull it fast even when busy with bz2..

Polossatik said:
If someone would have any idea of what more diagnostic info to provide
dmesg output.

here you go

Code:
-- started pandora using hotfix3 from nand, just let it startup with wifi enabled (autoconnect to my network)
-- dmesg output after startup:

[   64.681365] phy0: Inserted STA cd65a9e8
[   64.766815] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   75.124603] wlan0: no IPv6 routers present
-- I insert here the SD card
[   85.788757] mmc0: host does not support reading read-only switch. assuming write-enable.
[   85.796936] mmc0: new high speed SDHC card at address 0007
[   85.802947] mmcblk1: mmc0:0007 SD04G 3919872KiB 
[   85.807983]  mmcblk1: p1
[   86.272521] FAT: invalid media value (0x00)
[   86.276824] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[   86.428741] FAT: invalid media value (0x00)
[   86.433013] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[   86.887359] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended

-- Now i start DD

openpandora:~$ sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null
dd: reading `/dev/mmcblk1': Input/output error
25824+0 records in
25824+0 records out
13221888 bytes (13 MB) copied, 23.4888 s, 563 kB/s

-- no errors until I start the browser (= wifi is actually used), the DD errors out almost immediately

openpandora:~$ dmesg

-- removed the lines who where already present --


[   86.433013] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[   86.887359] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended
[  189.369628] keyboard.c: can't emulate rawmode for keycode 184
[  189.520111] keyboard.c: can't emulate rawmode for keycode 184
[  305.720642] mmci-omap mmci-omap.0: MMC IRQ 0x208000 : ERRI DCRC
[  305.721038] mmcblk1: error -84 transferring data
[  305.725677] end_request: I/O error, dev mmcblk1, sector 25824
[  305.731475] Buffer I/O error on device mmcblk1, logical block 3228
[  305.737701] end_request: I/O error, dev mmcblk1, sector 25832
[  305.743499] Buffer I/O error on device mmcblk1, logical block 3229
[  305.749725] end_request: I/O error, dev mmcblk1, sector 25840
[  305.755493] Buffer I/O error on device mmcblk1, logical block 3230
[  305.761718] end_request: I/O error, dev mmcblk1, sector 25848
[  305.767486] Buffer I/O error on device mmcblk1, logical block 3231
[  305.773712] end_request: I/O error, dev mmcblk1, sector 25856
[  305.779479] Buffer I/O error on device mmcblk1, logical block 3232
[  305.785705] end_request: I/O error, dev mmcblk1, sector 25864
[  305.791473] Buffer I/O error on device mmcblk1, logical block 3233
[  305.797698] end_request: I/O error, dev mmcblk1, sector 25872
[  305.803466] Buffer I/O error on device mmcblk1, logical block 3234
[  305.809692] end_request: I/O error, dev mmcblk1, sector 25880
[  305.815460] Buffer I/O error on device mmcblk1, logical block 3235
[  305.821685] end_request: I/O error, dev mmcblk1, sector 25888
[  305.827484] Buffer I/O error on device mmcblk1, logical block 3236
[  305.833679] end_request: I/O error, dev mmcblk1, sector 25896
[  305.839477] Buffer I/O error on device mmcblk1, logical block 3237
[  305.845672] end_request: I/O error, dev mmcblk1, sector 25904
[  305.851470] end_request: I/O error, dev mmcblk1, sector 25912
[  305.857238] end_request: I/O error, dev mmcblk1, sector 25920
[  305.863037] end_request: I/O error, dev mmcblk1, sector 25928
[  305.868804] end_request: I/O error, dev mmcblk1, sector 25936
[  305.874603] end_request: I/O error, dev mmcblk1, sector 25944
[  305.881805] mmci-omap mmci-omap.0: MMC IRQ 0x208000 : ERRI DCRC
[  305.953674] mmcblk1: error -84 transferring data
[  305.958343] end_request: I/O error, dev mmcblk1, sector 25952
[  305.964141] end_request: I/O error, dev mmcblk1, sector 25960
[  305.969940] end_request: I/O error, dev mmcblk1, sector 25968
[  305.975708] end_request: I/O error, dev mmcblk1, sector 25976
[  305.981506] end_request: I/O error, dev mmcblk1, sector 25984
[  305.987274] end_request: I/O error, dev mmcblk1, sector 25992
[  305.993072] end_request: I/O error, dev mmcblk1, sector 26000
[  305.998840] end_request: I/O error, dev mmcblk1, sector 26008
[  306.004638] end_request: I/O error, dev mmcblk1, sector 26016
[  306.010406] end_request: I/O error, dev mmcblk1, sector 26024
[  306.016204] end_request: I/O error, dev mmcblk1, sector 26032
[  306.021972] end_request: I/O error, dev mmcblk1, sector 26040
[  306.027770] end_request: I/O error, dev mmcblk1, sector 26048
[  306.033538] end_request: I/O error, dev mmcblk1, sector 26056
[  306.039306] end_request: I/O error, dev mmcblk1, sector 26064
[  306.045104] end_request: I/O error, dev mmcblk1, sector 26072
openpandora:~$

note the fact that this is again the same Sd card and the data offset is different, also the fact that it really seams related to actually using wifi
I'll now run it with wifi disabled and see what it gives
 
Last edited by a moderator:
torpor said:
This looks like a cache leak between wifi and SD drivers ..
What makes you bring up such conclusion? I only see MMC1 controller (that is connected to card) reporting data CRC errors, no telling why it decides it has got data corruption..
 
Last edited by a moderator:
Hm, maybe the SD Driver is starting to do I/O errors when CPU usage is high?
Anyone tried doing this while playing mupen, e.g.?

Or checked top what happens while SD and browser are used at the same time?
 
I'm not sure what is going on but some things are a bit bizarre.

Note the fact that the second time dd fails with just the same error/amount of data but there are NO I/O errors in DMESG.
where is this coming from?
once wifi is disabled and I remove/re-insert the same SD card no errors are seen (at least not the first 887 MB - did a control c after 40 minutes..)

Code:
sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null

[ 1462.844818] wlan0: deauthenticating from cd34282c by local choice (reason=3)
[ 1462.992126] wlan0: authenticate with cd3371c8 (try 1)
[ 1463.000488] wlan0: authenticated
[ 1463.000549] phy0: device now idle
[ 1463.023864] phy0: device no longer idle - working
[ 1463.046813] wlan0: associate with cd11cf08 (try 1)
[ 1463.055358] wlan0: RX AssocResp from cf1ea41a (capab=0x431 status=0 aid=2)
[ 1463.055389] wlan0: associated
[ 1463.055419] phy0: Allocated STA cb880de8
[ 1463.056762] phy0: Inserted STA cb880de8
[ 1463.144714] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 1473.476440] wlan0: no IPv6 routers present
[ 1846.353210] mmc0: host does not support reading read-only switch. assuming write-enable.
[ 1846.361389] mmc0: new high speed SDHC card at address 0007
[ 1846.367462] mmcblk1: mmc0:0007 SD04G 3919872KiB 
[ 1846.372436]  mmcblk1: p1
[ 1846.836517] FAT: invalid media value (0x00)
[ 1846.840728] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[ 1846.992950] FAT: invalid media value (0x00)
[ 1846.997161] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[ 1847.457946] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended
openpandora:~$ sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null

We trust you have received the usual lecture from the local System
Administrator. It usually boils down to these three things:

    #1) Respect the privacy of others.
    #2) Think before you type.
    #3) With great power comes great responsibility.

Password: 
dd: reading `/dev/mmcblk1': Input/output error
19936+0 records in
19936+0 records out
10207232 bytes (10 MB) copied, 14.922 s, 684 kB/s
openpandora:~$ 

-- now checking dmseg

 1846.997161] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[ 1847.457946] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended
[ 1909.393768] mmci-omap mmci-omap.0: MMC IRQ 0x208000 : ERRI DCRC
[ 1909.394134] mmcblk1: error -84 transferring data
[ 1909.398834] end_request: I/O error, dev mmcblk1, sector 19936
[ 1909.404632] Buffer I/O error on device mmcblk1, logical block 2492
[ 1909.410888] end_request: I/O error, dev mmcblk1, sector 19944
[ 1909.416656] Buffer I/O error on device mmcblk1, logical block 2493
[ 1909.422882] end_request: I/O error, dev mmcblk1, sector 19952
[ 1909.428649] Buffer I/O error on device mmcblk1, logical block 2494
[ 1909.434875] end_request: I/O error, dev mmcblk1, sector 19960
[ 1909.440643] Buffer I/O error on device mmcblk1, logical block 2495
[ 1909.446868] end_request: I/O error, dev mmcblk1, sector 19968
[ 1909.452636] Buffer I/O error on device mmcblk1, logical block 2496
[ 1909.458862] end_request: I/O error, dev mmcblk1, sector 19976
[ 1909.464630] Buffer I/O error on device mmcblk1, logical block 2497
[ 1909.470855] end_request: I/O error, dev mmcblk1, sector 19984
[ 1909.476654] Buffer I/O error on device mmcblk1, logical block 2498
[ 1909.482849] end_request: I/O error, dev mmcblk1, sector 19992
[ 1909.488647] Buffer I/O error on device mmcblk1, logical block 2499
[ 1909.494842] end_request: I/O error, dev mmcblk1, sector 20000
[ 1909.500640] Buffer I/O error on device mmcblk1, logical block 2500
[ 1909.506866] end_request: I/O error, dev mmcblk1, sector 20008
[ 1909.512634] Buffer I/O error on device mmcblk1, logical block 2501
[ 1909.518859] end_request: I/O error, dev mmcblk1, sector 20016
[ 1909.524627] end_request: I/O error, dev mmcblk1, sector 20024
[ 1909.530426] end_request: I/O error, dev mmcblk1, sector 20032
[ 1909.536193] end_request: I/O error, dev mmcblk1, sector 20040
[ 1909.541961] end_request: I/O error, dev mmcblk1, sector 20048
[ 1909.547760] end_request: I/O error, dev mmcblk1, sector 20056
openpandora:~$ 

-- now disable wifi

[ 2050.665832] aufs test_add:243:mount[1829]: uid/gid/perm /mnt/pnd/op_wifi 1000/1000/0755, 0/0/0777
[ 2051.414550] phy0: Removed STA cb880de8
[ 2051.414581] phy0: Destroyed STA cb880de8
[ 2051.414611] wlan0: deauthenticating from cd34282c by local choice (reason=3)
[ 2051.414794] phy0: device now idle
[ 2051.492553] wl1251: down
[ 2051.507904] Pandora WiFi: Remove started
[ 2051.507934] Sending remove event for MMC3...
[ 2051.515655] cfg80211: Calling CRDA to update world regulatory domain
[ 2051.538970] Pandora WiFi: Remove finished
[ 2051.667663] wl1251: unloaded
[ 2051.711425] mmc2: card 0001 removed

now test again

openpandora:~$ sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null
dd: reading `/dev/mmcblk1': Input/output error
19936+0 records in
19936+0 records out
10207232 bytes (10 MB) copied, 10.3702 s, 984 kB/s

same error but nothing new in dmesg

[ 2051.507934] Sending remove event for MMC3...
[ 2051.515655] cfg80211: Calling CRDA to update world regulatory domain
[ 2051.538970] Pandora WiFi: Remove finished
[ 2051.667663] wl1251: unloaded
[ 2051.711425] mmc2: card 0001 removed
openpandora:~$ 

-- now remove and insert card again

2051.711425] mmc2: card 0001 removed
[ 2313.703125] mmc0: card 0007 removed
[ 2313.883789] __ratelimit: 6 callbacks suppressed
[ 2313.888366] Buffer I/O error on device mmcblk1p1, logical block 0
[ 2313.894622] lost page write due to I/O error on mmcblk1p1
[ 2322.587615] mmc0: host does not support reading read-only switch. assuming write-enable.
[ 2322.595794] mmc0: new high speed SDHC card at address 0007
[ 2322.601867] mmcblk1: mmc0:0007 SD04G 3919872KiB 
[ 2322.606811]  mmcblk1: p1
[ 2323.093139] FAT: invalid media value (0x00)
[ 2323.097412] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[ 2323.252899] FAT: invalid media value (0x00)
[ 2323.257141] VFS: Can't find a valid FAT filesystem on dev mmcblk1.
[ 2323.747009] EXT2-fs warning: mounting unchecked fs, running e2fsck is recommended

openpandora:~$ $ sudo dd if=/dev/mmcblk1 |bzip2 >/dev/null

-- now works and does not fail (at least not the first 887 MB , I did a control-c after 40 minutes- can't be bothered to leave this running longer)
 
Notaz: nothing in particular, just the fact that after exercising wifi, SD I/O starts reporting errors .. I've seen the same behaviour on my Pandora, too. If I ping-flood my Pandora, SD reads get corrupted and I get the same messages in dmesg as reported above.

Maybe this only works with some SD cards, though? I guess we have to work out the SD card differences between tests, especially if you (notaz) haven't seen this yet, personally ..
 
EvilDragon said:
Hm, maybe the SD Driver is starting to do I/O errors when CPU usage is high?
Hardware is reporting the errors with an interrupt, not the driver.

torpor said:
Maybe this only works with some SD cards, though? I guess we have to work out the SD card differences between tests, especially if you (notaz) haven't seen this yet, personally ..
It's a bit difficult because same brands don't mean same hardware, as they tend to change chips and counterfeit cards exist.
 
Last edited by a moderator:
Back
Top