Port-arm archive

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]

Re: strange ld(4) behavior when reading off end of disk



mlelstv%serpens.de@localhost (Michael van Elst) writes:

>>My c partition size is 62333952, so it seems ok.
>
> Try to do the same but read with a larger block size.

I did, with block sizes 1m down to 1 sector.

>>Is there some missing bounds checking in ld, perhaps?
>>Am I confused?
>>Other ideas?
>
> The SD card seem to fail an MMC_READ_BLOCK_MULTIPLE command for
> the last device block. The command basically starts reading
> sequentially and is stopped by a MMC_STOP_TRANSMISSION command
> (that might be issued automatically by the controller). This edge
> case seems to have a problem somewhere.
>
> If you do 512 byte I/O the MMC_READ_BLOCK_SINGLE command is used
> and you don't get an error when reading the last block.

I see - didn't think that there would be a different command.

I also didn't realize that the higher-level code had windowed the big
read to the disk size -- which seems like nice, correct, behavior now
that I think about it.

> N.B. there is a bad boundary check in sdmmc too, but it has no effect
> since ld(4) does a correct boundary check and here we get the error
> just before the boundary is exceeded.

Are you saying this is a bug in my particular uSD card, basically that
the kernel is doing a valid IO operation and the card is incorrectly
handling it?  That is how it is seeming to me now that I have looked in
more detail.

I believe my card is a sandisk, not something expected to be dodgy.

  [     1.657646] sdmmc0: direct I/O error 5, r=6 p=0xba1e3f2c write
  [     1.697649] sdmmc0: SD card status: 4-bit, C10, U1, A1
  [     1.708641] ld0 at sdmmc0: <0x03:0x5344:SL32G:0x80:0x241f2b31:0x118>
  [     1.718247] ld0: 30436 MB, 7729 cyl, 128 head, 63 sec, 512 bytes/sect x 62333952 sectors
  [     1.728247] ld0: 4-bit width, High-Speed/SDR25, 50.000 MHz

I wonder if we should have a quirk, or if this is just buggy hardware.
Perhaps fall back to sequential to fill the buffer after an error?

I used 1m, and iseek'd ahead:

  $ dd if=/dev/rld0c of=/dev/null iseek=30436 bs=1m
  dd: /dev/rld0c: Input/output error
  0+0 records in
  0+0 records out
  0 bytes transferred in 4.502 secs (0 bytes/sec)

which produced:

  [ 1385560.114941] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385560.955099] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385561.785135] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385562.615169] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385563.445203] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385564.275237] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0)

Going smaller:

  $ dd if=/dev/rld0c of=/dev/null iseek=60872 bs=512k
  dd: /dev/rld0c: Input/output error
  0+0 records in
  0+0 records out
  0 bytes transferred in 4.496 secs (0 bytes/sec)

  [ 1385764.054273] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385764.884333] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385765.714420] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385766.544534] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385767.374583] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385768.204674] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=121744 bs=256k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  262144 bytes transferred in 4.493 secs (58344 bytes/sec)

  [ 1385857.738669] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385858.568703] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385859.398737] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385860.228772] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385861.058805] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385861.888840] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=243490 bs=128k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  131072 bytes transferred in 4.485 secs (29224 bytes/sec)

  { 1385950.992477] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385951.822512] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385952.652547] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385953.482579] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385954.312613] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1385955.142648] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=486982 bs=64k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  65536 bytes transferred in 4.480 secs (14628 bytes/sec)

  [ 1386040.066157] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1386040.896192] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1386041.726226] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1386042.556261] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1386043.386295] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0), retrying
  [ 1386044.216329] ld0c: error reading fsbn 62333824 of 62333824-62333951 (ld0 bn 62333824; cn 30436 tn 28 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=973966 bs=32k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  32768 bytes transferred in 4.439 secs (7381 bytes/sec)

  [ 1386097.899438] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0), retrying
  [ 1386098.719471] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0), retrying
  [ 1386099.539504] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0), retrying
  [ 1386100.359540] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0), retrying
  [ 1386101.179572] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0), retrying
  [ 1386101.999607] ld0c: error reading fsbn 62333888 of 62333888-62333951 (ld0 bn 62333888; cn 30436 tn 30 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=1947934 bs=16k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  16384 bytes transferred in 4.432 secs (3696 bytes/sec)

  [ 1386481.697493] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0), retrying
  [ 1386482.517529] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0), retrying
  [ 1386483.337562] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0), retrying
  [ 1386484.157598] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0), retrying
  [ 1386484.977636] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0), retrying
  [ 1386485.797670] ld0c: error reading fsbn 62333920 of 62333920-62333951 (ld0 bn 62333920; cn 30436 tn 31 sn 0)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=3895870 bs=8k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  8192 bytes transferred in 4.440 secs (1845 bytes/sec)

  [ 1386551.050367] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16), retrying
  [ 1386551.870402] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16), retrying
  [ 1386552.690435] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16), retrying
  [ 1386553.510469] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16), retrying
  [ 1386554.330502] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16), retrying
  [ 1386555.150539] ld0c: error reading fsbn 62333936 of 62333936-62333951 (ld0 bn 62333936; cn 30436 tn 31 sn 16)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=7791742 bs=4k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  4096 bytes transferred in 4.429 secs (924 bytes/sec)

  [ 1386602.012491] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24), retrying
  [ 1386602.832524] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24), retrying
  [ 1386603.652556] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24), retrying
  [ 1386604.472599] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24), retrying
  [ 1386605.292630] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24), retrying
  [ 1386606.112664] ld0c: error reading fsbn 62333944 of 62333944-62333951 (ld0 bn 62333944; cn 30436 tn 31 sn 24)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=15583486 bs=2k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  2048 bytes transferred in 4.432 secs (462 bytes/sec)

  [ 1386659.675297] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28), retrying
  [ 1386660.495361] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28), retrying
  [ 1386661.315471] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28), retrying
  [ 1386662.135519] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28), retrying
  [ 1386662.955592] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28), retrying
  [ 1386663.775638] ld0c: error reading fsbn 62333948 of 62333948-62333951 (ld0 bn 62333948; cn 30436 tn 31 sn 28)

and

  $ dd if=/dev/rld0c of=/dev/null iseek=31166974 bs=1k
  dd: /dev/rld0c: Input/output error
  1+0 records in
  1+0 records out
  1024 bytes transferred in 4.430 secs (231 bytes/sec)

  [ 1386726.288313] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30), retrying
  [ 1386727.108346] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30), retrying
  [ 1386727.928381] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30), retrying
  [ 1386728.748413] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30), retrying
  [ 1386729.568447] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30), retrying
  [ 1386730.388480] ld0c: error reading fsbn 62333950 of 62333950-62333951 (ld0 bn 62333950; cn 30436 tn 31 sn 30)

and finally

  $ dd if=/dev/rld0c of=/dev/null iseek=62333950
  2+0 records in
  2+0 records out
  1024 bytes transferred in 0.003 secs (341333 bytes/sec)

  $ dd if=/dev/rld0c of=/dev/null iseek=62333952
  0+0 records in
  0+0 records out
  0 bytes transferred in 0.001 secs (0 bytes/sec)

  (nothing in dmesg)

What I didn't follow before grasping your hypothesis that the card is
buggy, is that 62333952 converted to hex is

  3B72400

which is fairly even in binary, wtih 10 bits of zeroes;
62333952 = 60873 * 1024.

Attachment: signature.asc
Description: PGP signature



Home | Main Index | Thread Index | Old Index