2018-05-18 23:01:28

by John Stultz

Subject: REGRESSION: HiKey eMMC corruption

The last few months have been busy and I've not been ontop of my
upstream testing as well as I'd like, but today I did manage to chase
down an issue I've been seeing since 4.17-rc1 on the HiKey board,
which was causing emmc corruption and stopping the board from booting.

Symptoms usually looked like:
[ 1.690448] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
...
[ 1.777288] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 1.777760] mmc0: new HS200 MMC card at address 0001
...
[ 12.214381] dwmmc_k3 f723d000.dwmmc0: Unexpected command timeout, state 3
[ 12.457420] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 12.536676] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 12.616827] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 12.695742] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 12.772067] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 12.850429] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 12.863384] print_req_error: I/O error, dev mmcblk0, sector 8810504
[ 12.869778] Aborting journal on device mmcblk0p10-8.
[ 12.887900] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 12.967509] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 13.130182] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 13.209438] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 13.302085] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 13.380462] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 13.494539] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
req 400000Hz, actual 400000HZ div = 31)
[ 13.571420] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
req 150000000Hz, actual 148800000HZ div = 0)
[ 13.640817] EXT4-fs error (device mmcblk0p10):
ext4_journal_check_start:61: Detected aborted journal
[ 13.650043] EXT4-fs (mmcblk0p10): Remounting filesystem read-only

And quite often this would result in a disk that wouldn't properly
boot even with older kernels.

I've narrowed the issue down to the following change:
abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on eMMC")

Reverting this change seems to make things work reliably for me.

Should we revert that upstream for now?

thanks
-john

2018-05-21 08:34:52

by Wei Xu

Subject: Re: REGRESSION: HiKey eMMC corruption

Hi John,

On 2018/5/18 23:59, John Stultz wrote:
> The last few months have been busy and I've not been ontop of my
> upstream testing as well as I'd like, but today I did manage to chase
> down an issue I've been seeing since 4.17-rc1 on the HiKey board,
> which was causing emmc corruption and stopping the board from booting.
>
> Symptoms usually looked like:
> [ 1.690448] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> ...
> [ 1.777288] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 1.777760] mmc0: new HS200 MMC card at address 0001
> ...
> [ 12.214381] dwmmc_k3 f723d000.dwmmc0: Unexpected command timeout, state 3
> [ 12.457420] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 12.536676] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 12.616827] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 12.695742] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 12.772067] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 12.850429] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 12.863384] print_req_error: I/O error, dev mmcblk0, sector 8810504
> [ 12.869778] Aborting journal on device mmcblk0p10-8.
> [ 12.887900] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 12.967509] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 13.130182] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 13.209438] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 13.302085] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 13.380462] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 13.494539] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> req 400000Hz, actual 400000HZ div = 31)
> [ 13.571420] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> req 150000000Hz, actual 148800000HZ div = 0)
> [ 13.640817] EXT4-fs error (device mmcblk0p10):
> ext4_journal_check_start:61: Detected aborted journal
> [ 13.650043] EXT4-fs (mmcblk0p10): Remounting filesystem read-only
>
> And quite often this would result in a disk that wouldn't properly
> boot even with older kernels.
>
> I've narrowed the issue down to the following change:
> abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on eMMC")
>
> Reverting this change seems to make things work reliably for me.

Thanks to report this!
Let me check with Leo and Guodong to know which property changing
this is caused by.

Hi Leo and Guodong,

Can you help to confirm the commit abd7d0972a192?
From the log it seemed to cause by the property "max-frequency".

Thanks!

Best Regards,
Wei


>
> Should we revert that upstream for now?
>
> thanks
> -john
>
> .
>

2018-05-21 09:04:39

by Leo Yan

Subject: Re: REGRESSION: HiKey eMMC corruption

Hi Wei, John,

On Mon, May 21, 2018 at 09:34:04AM +0100, Wei Xu wrote:
> Hi John,
>
> On 2018/5/18 23:59, John Stultz wrote:
> > The last few months have been busy and I've not been ontop of my
> > upstream testing as well as I'd like, but today I did manage to chase
> > down an issue I've been seeing since 4.17-rc1 on the HiKey board,
> > which was causing emmc corruption and stopping the board from booting.
> >
> > Symptoms usually looked like:
> > [ 1.690448] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > ...
> > [ 1.777288] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 1.777760] mmc0: new HS200 MMC card at address 0001
> > ...
> > [ 12.214381] dwmmc_k3 f723d000.dwmmc0: Unexpected command timeout, state 3
> > [ 12.457420] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 12.536676] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 12.616827] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 12.695742] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 12.772067] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 12.850429] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 12.863384] print_req_error: I/O error, dev mmcblk0, sector 8810504
> > [ 12.869778] Aborting journal on device mmcblk0p10-8.
> > [ 12.887900] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 12.967509] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 13.130182] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 13.209438] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 13.302085] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 13.380462] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 13.494539] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
> > req 400000Hz, actual 400000HZ div = 31)
> > [ 13.571420] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
> > req 150000000Hz, actual 148800000HZ div = 0)
> > [ 13.640817] EXT4-fs error (device mmcblk0p10):
> > ext4_journal_check_start:61: Detected aborted journal
> > [ 13.650043] EXT4-fs (mmcblk0p10): Remounting filesystem read-only
> >
> > And quite often this would result in a disk that wouldn't properly
> > boot even with older kernels.
> >
> > I've narrowed the issue down to the following change:
> > abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on eMMC")
> >
> > Reverting this change seems to make things work reliably for me.
>
> Thanks to report this!
> Let me check with Leo and Guodong to know which property changing
> this is caused by.
>
> Hi Leo and Guodong,
>
> Can you help to confirm the commit abd7d0972a192?
> From the log it seemed to cause by the property "max-frequency".

The commit abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on
eMMC") can work well on my Hikey620 board, my Hikey620 board is
Lemaker version with 8GB Samsung emmc flash.

John, are you using different Hikey manufacturing version?

Thanks,
Leo Yan

2018-05-21 17:16:42

by John Stultz

Subject: Re: REGRESSION: HiKey eMMC corruption

On Mon, May 21, 2018 at 2:03 AM, Leo Yan <[email protected]> wrote:
> Hi Wei, John,
>
> On Mon, May 21, 2018 at 09:34:04AM +0100, Wei Xu wrote:
>> Hi John,
>>
>> On 2018/5/18 23:59, John Stultz wrote:
>> > The last few months have been busy and I've not been ontop of my
>> > upstream testing as well as I'd like, but today I did manage to chase
>> > down an issue I've been seeing since 4.17-rc1 on the HiKey board,
>> > which was causing emmc corruption and stopping the board from booting.
>> >
>> > Symptoms usually looked like:
>> > [ 1.690448] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > ...
>> > [ 1.777288] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 1.777760] mmc0: new HS200 MMC card at address 0001
>> > ...
>> > [ 12.214381] dwmmc_k3 f723d000.dwmmc0: Unexpected command timeout, state 3
>> > [ 12.457420] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 12.536676] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 12.616827] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 12.695742] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 12.772067] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 12.850429] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 12.863384] print_req_error: I/O error, dev mmcblk0, sector 8810504
>> > [ 12.869778] Aborting journal on device mmcblk0p10-8.
>> > [ 12.887900] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 12.967509] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 13.130182] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 13.209438] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 13.302085] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 13.380462] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 13.494539] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> > req 400000Hz, actual 400000HZ div = 31)
>> > [ 13.571420] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> > req 150000000Hz, actual 148800000HZ div = 0)
>> > [ 13.640817] EXT4-fs error (device mmcblk0p10):
>> > ext4_journal_check_start:61: Detected aborted journal
>> > [ 13.650043] EXT4-fs (mmcblk0p10): Remounting filesystem read-only
>> >
>> > And quite often this would result in a disk that wouldn't properly
>> > boot even with older kernels.
>> >
>> > I've narrowed the issue down to the following change:
>> > abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on eMMC")
>> >
>> > Reverting this change seems to make things work reliably for me.
>>
>> Thanks to report this!
>> Let me check with Leo and Guodong to know which property changing
>> this is caused by.
>>
>> Hi Leo and Guodong,
>>
>> Can you help to confirm the commit abd7d0972a192?
>> From the log it seemed to cause by the property "max-frequency".
>
> The commit abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on
> eMMC") can work well on my Hikey620 board, my Hikey620 board is
> Lemaker version with 8GB Samsung emmc flash.
>
> John, are you using different Hikey manufacturing version?

No, its a standard 8gb version. Later today I'll try to narrow down
if only part of the dts changes can be reverted.

thanks
-john

2018-05-21 19:10:08

by John Stultz

Subject: Re: REGRESSION: HiKey eMMC corruption

On Mon, May 21, 2018 at 1:34 AM, Wei Xu <[email protected]> wrote:
> On 2018/5/18 23:59, John Stultz wrote:
>> The last few months have been busy and I've not been ontop of my
>> upstream testing as well as I'd like, but today I did manage to chase
>> down an issue I've been seeing since 4.17-rc1 on the HiKey board,
>> which was causing emmc corruption and stopping the board from booting.
>>
>> Symptoms usually looked like:
>> [ 1.690448] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> ...
>> [ 1.777288] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 1.777760] mmc0: new HS200 MMC card at address 0001
>> ...
>> [ 12.214381] dwmmc_k3 f723d000.dwmmc0: Unexpected command timeout, state 3
>> [ 12.457420] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 12.536676] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 12.616827] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 12.695742] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 12.772067] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 12.850429] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 12.863384] print_req_error: I/O error, dev mmcblk0, sector 8810504
>> [ 12.869778] Aborting journal on device mmcblk0p10-8.
>> [ 12.887900] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 12.967509] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 13.130182] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 13.209438] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 13.302085] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 13.380462] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 13.494539] mmc_host mmc0: Bus speed (slot 0) = 24800000Hz (slot
>> req 400000Hz, actual 400000HZ div = 31)
>> [ 13.571420] mmc_host mmc0: Bus speed (slot 0) = 148800000Hz (slot
>> req 150000000Hz, actual 148800000HZ div = 0)
>> [ 13.640817] EXT4-fs error (device mmcblk0p10):
>> ext4_journal_check_start:61: Detected aborted journal
>> [ 13.650043] EXT4-fs (mmcblk0p10): Remounting filesystem read-only
>>
>> And quite often this would result in a disk that wouldn't properly
>> boot even with older kernels.
>>
>> I've narrowed the issue down to the following change:
>> abd7d0972a192 ("arm64: dts: hikey: Enable HS200 mode on eMMC")
>>
>> Reverting this change seems to make things work reliably for me.
>
> Thanks to report this!
> Let me check with Leo and Guodong to know which property changing
> this is caused by.
>
> Hi Leo and Guodong,
>
> Can you help to confirm the commit abd7d0972a192?
> From the log it seemed to cause by the property "max-frequency".

So yes, I can confirm that if I drop only the max-frequency property
out, keeping the "mmc-hs200-1_8v;" line it still boots for me.

thanks
-john