[Miscellaneous Android Development] blahmartinblah:
Hi guys

I spent a few more hours testing. Here is some new information.

I have gone back to CM13 2016-08-17.

1. I found an old 2Gb Sandisk SD card. It is still exhibiting similar problems for me. So the ultra high speed stuff might not be the issue.

2. Here is what I found on the 2Gb HS card:

- Checked the contents of the card using my PC card reader - found that it was used in one of my old android phones and still had contents including photos etc. It was FAT format.

- Installed the card as-is, and rebooted many times (about 20) but could not get it to mount.

- I put it into my PC card reader and slow-formatted it to FAT32. As soon as I booted the phone, it detected it. Brilliant!

- The phone was shut down cleanly, but with 3 further power cycles and boot attempts, the card does not mount

- Again put it in the PC card reader and slow-format to FAT32. Return the card to the Trunk which detects the card on the first boot.

- 3 further power cycles and boot attempts, but card does not mount

- Checked the card in my PC card reader. The windows CHKDSK utility reports errors with the first allocation units on \LOST.DIR and \Android folders.

Log with 2Gb HS card, first boot after format:

[ 0.595045] mmc1: no vqmmc regulator found
[ 0.595057] mmc1: no vmmc regulator found
[ 0.595322] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 0.595332] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 0 curr_io_level 0
[ 0.595356] mmc1: Received IRQ(253), status=0x2
[ 0.597075] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.597092] mmc1: sdhci_msm_check_power_status: request 2 done
[ 0.608119] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.608184] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.619230] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 0.619236] mmc1: sdhci_msm_check_power_status: request 8 done
[ 0.624765] mmc1: SDHCI controller on 7864900.sdhci [7864900.sdhci] using 32-bit ADMA
[ 0.676785] mmc1: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[ 0.676804] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.676811] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 2 curr_io_level 8
[ 0.676825] mmc1: Received IRQ(253), status=0x1
[ 0.677437] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.677455] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.677463] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 1 curr_io_level 4
[ 0.677472] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.677484] mmc1: request to disable clocks
[ 0.679854] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 0.681078] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 0.681085] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 1 curr_io_level 4
[ 0.681098] mmc1: Received IRQ(253), status=0x2
[ 0.682872] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.682895] mmc1: sdhci_msm_check_power_status: request 2 done
[ 0.693923] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.693931] mmc1: request to enable clocks
[ 0.693996] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.705049] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 0.705054] mmc1: sdhci_msm_check_power_status: request 8 done
[ 0.711536] mmc1: clock 400000Hz busmode 1 powermode 2 cs 1 Vdd 18 width 0 timing 0
[ 0.711554] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.713756] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.713774] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.715580] mmc1: req failed (CMD5): -110, retrying...
[ 0.716055] mmc1: req failed (CMD5): -110, retrying...
[ 0.716529] mmc1: req failed (CMD5): -110, retrying...
[ 0.717624] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 17 width 0 timing 0
[ 0.717641] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.717682] mmc1: clock 400000Hz busmode 1 powermode 2 cs 1 Vdd 17 width 0 timing 0
[ 0.717698] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.719913] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 17 width 0 timing 0
[ 0.719929] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.756427] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 17 width 0 timing 2
[ 0.756449] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:2 ctrl_2:0x0
[ 0.756491] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 17 width 0 timing 2
[ 0.756499] mmc1: sdhci_msm_set_clock: setting clk rate to 50000000
[ 0.758138] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 0.758222] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 17 width 2 timing 2
[ 0.758234] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 0.758252] mmc1: new high speed SD card at address e624
[ 0.758529] mmcblk1: mmc1:e624 SU02G 1.84 GiB
[ 0.765636] mmc1: clk scaling enabled
[ 0.765680] mmc1: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[ 0.765692] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:0 ctrl_2:0x0
[ 0.765699] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 2 curr_io_level 8
[ 0.765715] mmc1: Received IRQ(253), status=0x1
[ 0.766315] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.766333] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.766342] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 1 curr_io_level 4
[ 0.766347] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.766353] mmc1: request to disable clocks
[ 0.961849] mmc1: frequency set to 0 in disable function, this means the clock is already disabled.
[ 2.406696] mmc1: Starting deferred resume
[ 2.406716] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 2.408360] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 2.408373] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 1 curr_io_level 4
[ 2.408417] mmc1: Received IRQ(253), status=0x2
[ 2.410255] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 2.410280] mmc1: sdhci_msm_check_power_status: request 2 done
[ 2.421326] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 2.421340] mmc1: request to enable clocks
[ 2.421350] mmc1: sdhci_msm_set_clock: setting clk rate to 400000
[ 2.423039] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 2.434141] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 2.434152] mmc1: sdhci_msm_check_power_status: request 8 done
[ 2.439727] mmc1: clock 400000Hz busmode 1 powermode 2 cs 1 Vdd 18 width 0 timing 0
[ 2.439760] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 2.441974] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 2.442000] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 2.473244] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 2
[ 2.473269] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:2 ctrl_2:0x0
[ 2.473310] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 2
[ 2.473318] mmc1: sdhci_msm_set_clock: setting clk rate to 50000000
[ 2.474968] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 2.475040] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 2.475053] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 2.475067] mmc1: clk scaling enabled
[ 2.475072] mmc1: Deferred resume completed
[ 2.671878] mmc1: clock 0Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 2.671897] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 2.671904] mmc1: request to disable clocks
[ 2.673538] mmc1: gated MCI clock
[ 12.491914] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 12.491933] mmc1: request to enable clocks
[ 12.493468] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 12.493506] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 12.493526] mmc1: ungated MCI clock
[ 12.493599] mmc1: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[ 12.493614] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:0 ctrl_2:0x0
[ 12.493642] mmc1: Received IRQ(253), status=0x1
[ 12.493678] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 2 curr_io_level 8
[ 12.494410] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 12.494436] mmc1: sdhci_msm_check_power_status: request 1 done
[ 12.494461] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 1 curr_io_level 4
[ 12.494469] mmc1: sdhci_msm_check_power_status: request 1 done
[ 12.494476] mmc1: request to disable clocks
[ 12.691926] mmc1: frequency set to 0 in disable function, this means the clock is already disabled.
[ 26.706646] mmc1: Starting deferred resume
[ 26.706665] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 26.708987] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 26.709000] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 1 curr_io_level 4
[ 26.709030] mmc1: Received IRQ(253), status=0x2
[ 26.711623] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 26.711656] mmc1: sdhci_msm_check_power_status: request 2 done
[ 26.722705] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 26.722720] mmc1: request to enable clocks
[ 26.722731] mmc1: sdhci_msm_set_clock: setting clk rate to 400000
[ 26.725789] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 26.737235] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 26.737243] mmc1: sdhci_msm_check_power_status: request 8 done
[ 26.742917] mmc1: clock 400000Hz busmode 1 powermode 2 cs 1 Vdd 18 width 0 timing 0
[ 26.742948] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 26.745464] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 26.745487] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 26.780499] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 2
[ 26.780532] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:2 ctrl_2:0x0
[ 26.780574] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 2
[ 26.780585] mmc1: sdhci_msm_set_clock: setting clk rate to 50000000
[ 26.782330] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 26.782425] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 26.782440] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 26.782456] mmc1: clk scaling enabled
[ 26.782462] mmc1: Deferred resume completed
[ 27.482086] mmc1: clock 0Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 27.482141] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 27.482149] mmc1: request to disable clocks
[ 27.486372] mmc1: gated MCI clock
[ 30.269464] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 30.269483] mmc1: request to enable clocks
[ 30.277407] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 30.277436] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 30.277456] mmc1: ungated MCI clock
[ 30.532047] mmc1: clock 0Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 30.532075] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 30.532084] mmc1: request to disable clocks
[ 30.535608] mmc1: gated MCI clock
[ 32.282118] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 32.282140] mmc1: request to enable clocks
[ 32.283893] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 32.283920] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 32.283941] mmc1: ungated MCI clock
[ 32.481915] mmc1: clock 0Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 32.481940] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 32.481948] mmc1: request to disable clocks
[ 32.485502] mmc1: gated MCI clock
[ 37.292007] mmc1: clock 50000000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 37.292023] mmc1: request to enable clocks
[ 37.294505] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 37.294532] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 37.294552] mmc1: ungated MCI clock
[ 37.491869] mmc1: clock 0Hz busmode 1 powermode 2 cs 0 Vdd 18 width 2 timing 2
[ 37.491892] mmc1: sdhci_msm_set_uhs_signaling-clock:50000000 uhs mode:2 ctrl_2:0x0
[ 37.491901] mmc1: request to disable clocks
[ 37.493364] mmc1: gated MCI clock

Log with 2Gb HS card, one of the subsequent boots:

[ 0.597284] mmc1: no vqmmc regulator found
[ 0.597296] mmc1: no vmmc regulator found
[ 0.597555] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 0.597564] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 0 curr_io_level 0
[ 0.597578] mmc1: Received IRQ(253), status=0x2
[ 0.599289] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.599309] mmc1: sdhci_msm_check_power_status: request 2 done
[ 0.610431] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.610495] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.621543] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 0.621549] mmc1: sdhci_msm_check_power_status: request 8 done
[ 0.627076] mmc1: SDHCI controller on 7864900.sdhci [7864900.sdhci] using 32-bit ADMA
[ 0.677623] mmc1: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[ 0.677641] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.677647] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 2 curr_io_level 8
[ 0.677662] mmc1: Received IRQ(253), status=0x1
[ 0.678277] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.678294] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.678302] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 1 curr_io_level 4
[ 0.678311] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.678323] mmc1: request to disable clocks
[ 0.681178] mmc1: clock 0Hz busmode 1 powermode 1 cs 0 Vdd 18 width 0 timing 0
[ 0.682500] mmc1: sdhci_msm_enable_controller_clock: enabled controller clock
[ 0.682508] mmc1: sdhci_msm_check_power_status: request 2 curr_pwr_state 1 curr_io_level 4
[ 0.682548] mmc1: Received IRQ(253), status=0x2
[ 0.684259] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.684277] mmc1: sdhci_msm_check_power_status: request 2 done
[ 0.694604] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.694611] mmc1: request to enable clocks
[ 0.694676] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.705322] mmc1: sdhci_msm_check_power_status: request 8 curr_pwr_state 2 curr_io_level 8
[ 0.705329] mmc1: sdhci_msm_check_power_status: request 8 done
[ 0.711810] mmc1: clock 400000Hz busmode 1 powermode 2 cs 1 Vdd 18 width 0 timing 0
[ 0.711828] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.714031] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.714048] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.716054] mmc1: req failed (CMD5): -110, retrying...
[ 0.716528] mmc1: req failed (CMD5): -110, retrying...
[ 0.717002] mmc1: req failed (CMD5): -110, retrying...
[ 0.719345] mmc1: clock 400000Hz busmode 1 powermode 2 cs 0 Vdd 18 width 0 timing 0
[ 0.719363] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.720263] mmc1: clock 0Hz busmode 1 powermode 0 cs 0 Vdd 0 width 0 timing 0
[ 0.720280] mmc1: sdhci_msm_set_uhs_signaling-clock:400000 uhs mode:0 ctrl_2:0x0
[ 0.720287] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 2 curr_io_level 8
[ 0.720307] mmc1: Received IRQ(253), status=0x1
[ 0.720914] mmc1: Handled IRQ(253), ret=0, ack=0x1
[ 0.720932] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.720941] mmc1: sdhci_msm_check_power_status: request 1 curr_pwr_state 1 curr_io_level 4
[ 0.720949] mmc1: sdhci_msm_check_power_status: request 1 done
[ 0.720961] mmc1: request to disable clocks
[ 0.922557] mmc1: frequency set to 0 in disable function, this means the clock is already disabled.