eMMC and "mkfs.ext3" hangs without "-E nodiscard"

Discussion:

Holger Schurig

2014-09-29 13:46:10 UTC

Hi all,

on kernel 3.16.3 running on an i.MX6 with an eMMC card formatting a
partition won't work, it hangs. With an added -v the last thing it
spit out is "Discarding device blocks: 4096/196608".

When I run mkfs with "-E nodiscard", formatting & booting works.

Noteworthy: when the eMMC device was still in virgin mode,
partitioning without "-E nodiscard" worked. But last week I used the
mmc tool to turn the user space into enhanced format. Basically, I
first run "mmc extcsd read /dev/mmcblk0" and used the number after
MAX_ENH_SIZE_MULT for an "mmc enh_area set -y 0 7651323 /dev/mmcblk0".
Then, after a power-cycle, I also turned bkops on because kernel was
complaining that it wasn't enabled. And since the default discard
option of mkfs.ext3 doesn't seem to work anymore.
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Arnd Bergmann

2014-09-29 14:12:22 UTC

Permalink

Post by Holger Schurig
on kernel 3.16.3 running on an i.MX6 with an eMMC card formatting a
partition won't work, it hangs. With an added -v the last thing it
spit out is "Discarding device blocks: 4096/196608".
When I run mkfs with "-E nodiscard", formatting & booting works.
Noteworthy: when the eMMC device was still in virgin mode,
partitioning without "-E nodiscard" worked. But last week I used the
mmc tool to turn the user space into enhanced format. Basically, I
first run "mmc extcsd read /dev/mmcblk0" and used the number after
MAX_ENH_SIZE_MULT for an "mmc enh_area set -y 0 7651323 /dev/mmcblk0".
Then, after a power-cycle, I also turned bkops on because kernel was
complaining that it wasn't enabled. And since the default discard
option of mkfs.ext3 doesn't seem to work anymore.

Are you sure that it's not just taking very long?

Can you try erasing a smaller region of the device using the program
below? Normally BLKDISCARD is very fast for a device that has been
erased or that is new, but depending on the device it can take a
while to erase actual data.

Arnd

----
#define _GNU_SOURCE

#include <sys/stat.h>
#include <sys/ioctl.h>
#include <sys/types.h>
#include <stdio.h>
#include <errno.h>
#include <fcntl.h>
#include <linux/fs.h>
#include <stdlib.h>

int main(int argc, char *argv[])
{
int fd = open(argv[1], O_RDWR | O_DIRECT);
int ret;
unsigned long long range[2];

if (argc != 4) {
fprintf(stderr, "usage: %s <device> <start> <length>\n",
argv[0]);
}

if (fd < 0) {
perror("open");
return errno;
}

range[0] = atoll(argv[2]);
range[1] = atoll(argv[3]);

printf("erasing %lld to %lld on %s\n", range[0], range[0] + range[1], argv[1]);

ret = ioctl(fd, BLKDISCARD, range);
if (ret)
perror("ioctl");

return errno;
}

--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Holger Schurig

2014-09-30 07:05:55 UTC

Permalink

Hi Arnd,

Post by Arnd Bergmann
Are you sure that it's not just taking very long?

Hmm, after one or two minutes I lost my patience. Also, hitting Ctrl-C
didn't abort the application. Suspending it with Ctrl-Z doesn't work
either. I did an strace, and the last few lines look like this:

stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_EXCL) = 3
close(3) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
uname({sys="Linux", node="mde", ...}) = 0
ioctl(3, BLKGETSIZE64, 0xbea40610) = 0
close(3) = 0
write(1, "fs_types for mke2fs.conf resolut"..., 37fs_types for
mke2fs.conf resolution: ) = 37
write(1, "'ext3'", 6'ext3') = 6
write(1, "\n", 1
) = 1
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
ioctl(3, BLKSSZGET, 0xbea408b8) = 0
close(3) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
ioctl(3, BLKPBSZGET, 0xbea408bc) = 0
close(3) = 0
stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
fadvise64_64(3, 0, 0, POSIX_FADV_RANDOM) = 0
fstat64(3, {st_mode=S_IFBLK|0660, st_rdev=makedev(179, 5), ...}) = 0
uname({sys="Linux", node="mde", ...}) = 0
ioctl(3, BLKGETSIZE64, 0x53a4b8) = 0
ioctl(3, CDROM_GET_CAPABILITY, 0) = -1 EINVAL (Invalid argument)
ioctl(3, BLKALIGNOFF, 0xbea40764) = 0
ioctl(3, BLKIOMIN, 0xbea40764) = 0
ioctl(3, BLKIOOPT, 0xbea40764) = 0
ioctl(3, BLKPBSZGET, 0xbea40764) = 0
ioctl(3, BLKSSZGET, 0x53a4d0) = 0
close(3) = 0
access("/sys/fs/ext4/features/lazy_itable_init", R_OK) = -1 ENOENT (No
such file or directory)
open("/dev/mmcblk0p1", O_RDWR|O_EXCL|O_LARGEFILE) = 3
stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
ioctl(3, BLKDISCARDZEROES, 0xbea40880) = 0
ioctl(3, BLKROGET, 0xbea40884) = 0
uname({sys="Linux", node="mde", ...}) = 0
gettimeofday({1403353145, 564428}, NULL) = 0
gettimeofday({1403353145, 564587}, NULL) = 0
gettimeofday({1403353145, 564709}, NULL) = 0
ioctl(3, BLKDISCARD

Too bad I cannot see the arguments/results from the ioctls ...

I also noticed that it takes an awful lot of kernel task time:

***@mde:~# top | head -n9
top - 14:09:59 up 2 min, 2 users, load average: 1.84, 0.79, 0.30
Tasks: 86 total, 2 running, 84 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.3 us, 22.2 sy, 0.0 ni, 54.6 id, 22.5 wa, 0.0 hi, 0.4 si, 0.0 st
KiB Mem: 1034092 total, 86760 used, 947332 free, 2808 buffers
KiB Swap: 0 total, 0 used, 0 free, 52128 cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
71 root 20 0 0 0 0 R 99.5 0.0 2:23.54 mmcqd/1
323 root 20 0 2640 1640 1304 R 5.5 0.2 0:00.02 top

Maybe it's hanging in the kernel ? The whan stays at get_request:

***@mde:~# ps -a -o pid,f,stat,pcpu,pmem,psr,comm,wchan=WIDE-WCHAN | grep mkfs
296 0 D+ 0.0 0.1 2 mkfs.ext3 get_request

Post by Arnd Bergmann
Can you try erasing a smaller region of the device

Sure, this seems to work.

***@mde:~# blkdiscard /dev/mmcblk0 0 1
erasing 0 to 1 on /dev/mmcblk0
ioctl: Invalid argument
***@mde:~# blkdiscard /dev/mmcblk0 0 512
erasing 0 to 512 on /dev/mmcblk0
***@mde:~# blkdiscard /dev/mmcblk0 0 4096
erasing 0 to 4096 on /dev/mmcblk0
***@mde:~# blkdiscard /dev/mmcblk0 0 8192
erasing 0 to 8192 on /dev/mmcblk0
***@mde:~# blkdiscard /dev/mmcblk0 0 16384
erasing 0 to 16386 on /dev/mmcblk0
ioctl: Invalid argument
***@mde:~# xxd -g0 </dev/mmcblk0 | head
0000000: 00000000000000000000000000000000 ................
0000010: 00000000000000000000000000000000 ................
0000020: 00000000000000000000000000000000 ................
0000030: 00000000000000000000000000000000 ................
0000040: 00000000000000000000000000000000 ................
0000050: 00000000000000000000000000000000 ................
0000060: 00000000000000000000000000000000 ................
0000070: 00000000000000000000000000000000 ................
0000080: 00000000000000000000000000000000 ................
0000090: 00000000000000000000000000000000 ................
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Arnd Bergmann

2014-09-30 10:16:26 UTC

Permalink

Post by Holger Schurig
Hmm, after one or two minutes I lost my patience. Also, hitting Ctrl-C
didn't abort the application. Suspending it with Ctrl-Z doesn't work
stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_EXCL) = 3
close(3) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
uname({sys="Linux", node="mde", ...}) = 0
ioctl(3, BLKGETSIZE64, 0xbea40610) = 0
close(3) = 0
write(1, "fs_types for mke2fs.conf resolut"..., 37fs_types for
mke2fs.conf resolution: ) = 37
write(1, "'ext3'", 6'ext3') = 6
write(1, "\n", 1
) = 1
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
ioctl(3, BLKSSZGET, 0xbea408b8) = 0
close(3) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
ioctl(3, BLKPBSZGET, 0xbea408bc) = 0
close(3) = 0
stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
open("/dev/mmcblk0p1", O_RDONLY|O_LARGEFILE) = 3
fadvise64_64(3, 0, 0, POSIX_FADV_RANDOM) = 0
fstat64(3, {st_mode=S_IFBLK|0660, st_rdev=makedev(179, 5), ...}) = 0
uname({sys="Linux", node="mde", ...}) = 0
ioctl(3, BLKGETSIZE64, 0x53a4b8) = 0
ioctl(3, CDROM_GET_CAPABILITY, 0) = -1 EINVAL (Invalid argument)
ioctl(3, BLKALIGNOFF, 0xbea40764) = 0
ioctl(3, BLKIOMIN, 0xbea40764) = 0
ioctl(3, BLKIOOPT, 0xbea40764) = 0
ioctl(3, BLKPBSZGET, 0xbea40764) = 0
ioctl(3, BLKSSZGET, 0x53a4d0) = 0
close(3) = 0
access("/sys/fs/ext4/features/lazy_itable_init", R_OK) = -1 ENOENT (No
such file or directory)
open("/dev/mmcblk0p1", O_RDWR|O_EXCL|O_LARGEFILE) = 3
stat64("/dev/mmcblk0p1", {st_mode=S_IFBLK|0660, st_rdev=makedev(179,
5), ...}) = 0
ioctl(3, BLKDISCARDZEROES, 0xbea40880) = 0
ioctl(3, BLKROGET, 0xbea40884) = 0
uname({sys="Linux", node="mde", ...}) = 0
gettimeofday({1403353145, 564428}, NULL) = 0
gettimeofday({1403353145, 564587}, NULL) = 0
gettimeofday({1403353145, 564709}, NULL) = 0
ioctl(3, BLKDISCARD
Too bad I cannot see the arguments/results from the ioctls ...

This is probably bug in 'strace', it's missing a handler for BLKDISCARD.
I believe, mkfs.ext3 just tries to erase the whole partition, which is
a good idea in principle.

Post by Holger Schurig
top - 14:09:59 up 2 min, 2 users, load average: 1.84, 0.79, 0.30
Tasks: 86 total, 2 running, 84 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.3 us, 22.2 sy, 0.0 ni, 54.6 id, 22.5 wa, 0.0 hi, 0.4 si, 0.0 st
KiB Mem: 1034092 total, 86760 used, 947332 free, 2808 buffers
KiB Swap: 0 total, 0 used, 0 free, 52128 cached
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
71 root 20 0 0 0 0 R 99.5 0.0 2:23.54 mmcqd/1
323 root 20 0 2640 1640 1304 R 5.5 0.2 0:00.02 top
296 0 D+ 0.0 0.1 2 mkfs.ext3 get_request

Right, mkfs is obviously wanting for the ioctl to complete, but that
seems to be stuck looking in mmcqd. It would be helpful to understand
where that kernel thread is stuck, but that is harder to do.

Is this sdhci-esdhc-imx.c? Are you using DMA mode?

Post by Holger Schurig

Post by Arnd Bergmann
Can you try erasing a smaller region of the device

Sure, this seems to work.
erasing 0 to 1 on /dev/mmcblk0
ioctl: Invalid argument
erasing 0 to 512 on /dev/mmcblk0
erasing 0 to 4096 on /dev/mmcblk0
erasing 0 to 8192 on /dev/mmcblk0
erasing 0 to 16386 on /dev/mmcblk0
ioctl: Invalid argument

16386 is not a multiple of 512, so that fails. Keep trying larger
power-of-two numbers, also using 'time' to see how long they take.
You should be able to erase up to 4GB at a time.

Arnd
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Uwe Kleine-König

2014-10-09 18:44:06 UTC

Permalink

Hello,

I had the exact same issue on an i.MX6 machine (via amos820) with
mkfs.ext2. When cross checking on a different i.MX6 machine the proble=
m
didn't happen there. It seems it didn't try to discard blocks, at least
it didn't say something about "Discarding device blocks:".

I tried to understand how mkfs.ext* decides if it can/should try to
discard blocks, but failed to do so. Theodore: Maybe you can help out
here? The relevant line seems to be:

discard =3D get_bool_from_profile(fs_types, "discard" , discard);

Unfortunately I don't have access to the failing machine anymore, still
it would be great to understand the problem.

Apart from that even if the block device somehow announces that it can
or cannot discard blocks, the process doing it anyhow shouldn't hang.
(For me it wasn't interruptible by Ctrl-C, so probably hung in a system
call.)

Best regards
Uwe

--=20
Pengutronix e.K. | Uwe Kleine-K=F6nig =
|
Industrial Linux Solutions | http://www.pengutronix.de/=
|
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html

Fabio Estevam

2014-10-09 20:40:27 UTC

Permalink

Hi Holger,

On Mon, Sep 29, 2014 at 10:46 AM, Holger Schurig

Post by Holger Schurig
Hi all,
on kernel 3.16.3 running on an i.MX6 with an eMMC card formatting a
partition won't work, it hangs. With an added -v the last thing it
spit out is "Discarding device blocks: 4096/196608".
When I run mkfs with "-E nodiscard", formatting & booting works.
Noteworthy: when the eMMC device was still in virgin mode,
partitioning without "-E nodiscard" worked. But last week I used the
mmc tool to turn the user space into enhanced format. Basically, I
first run "mmc extcsd read /dev/mmcblk0" and used the number after
MAX_ENH_SIZE_MULT for an "mmc enh_area set -y 0 7651323 /dev/mmcblk0".
Then, after a power-cycle, I also turned bkops on because kernel was
complaining that it wasn't enabled. And since the default discard
option of mkfs.ext3 doesn't seem to work anymore.

Can you try applying this series to see if it helps?
http://www.spinics.net/lists/linux-mmc/msg23656.html

It has been applied into linux-next already.
--
To unsubscribe from this list: send the line "unsubscribe linux-mmc" in
the body of a message to ***@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html