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

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

[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.

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

[Arnd Bergmann]

On Monday 29 September 2014 15:46:10 Holger Schurig wrote:
> 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;
}

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

[Holger Schurig]

Hi Arnd,

> 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:

root@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:

root@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



> Can you try erasing a smaller region of the device

Sure, this seems to work.

root@mde:~# blkdiscard /dev/mmcblk0 0 1
erasing 0 to 1 on /dev/mmcblk0
ioctl: Invalid argument
root@mde:~# blkdiscard /dev/mmcblk0 0 512
erasing 0 to 512 on /dev/mmcblk0
root@mde:~# blkdiscard /dev/mmcblk0 0 4096
erasing 0 to 4096 on /dev/mmcblk0
root@mde:~# blkdiscard /dev/mmcblk0 0 8192
erasing 0 to 8192 on /dev/mmcblk0
root@mde:~# blkdiscard /dev/mmcblk0 0 16384
erasing 0 to 16386 on /dev/mmcblk0
ioctl: Invalid argument
root@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  ................

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

[Arnd Bergmann]

On Tuesday 30 September 2014 09:05:55 Holger Schurig wrote:
> 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 ...

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.

> I also noticed that it takes an awful lot of kernel task time:
> 
> root@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:
> 
> root@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

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?
 
> > Can you try erasing a smaller region of the device
> 
> Sure, this seems to work.
> 
> root@mde:~# blkdiscard /dev/mmcblk0 0 1
> erasing 0 to 1 on /dev/mmcblk0
> ioctl: Invalid argument
> root@mde:~# blkdiscard /dev/mmcblk0 0 512
> erasing 0 to 512 on /dev/mmcblk0
> root@mde:~# blkdiscard /dev/mmcblk0 0 4096
> erasing 0 to 4096 on /dev/mmcblk0
> root@mde:~# blkdiscard /dev/mmcblk0 0 8192
> erasing 0 to 8192 on /dev/mmcblk0
> root@mde:~# blkdiscard /dev/mmcblk0 0 16384
> 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

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

[Uwe Kleine-König]

Hello,

On Mon, Sep 29, 2014 at 03:46:10PM +0200, Holger Schurig wrote:
> 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.
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 problem
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 = 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

-- 
Pengutronix e.K.                           | Uwe Kleine-König            |
Industrial Linux Solutions                 | http://www.pengutronix.de/  |

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

[Fabio Estevam]

Hi Holger,

On Mon, Sep 29, 2014 at 10:46 AM, Holger Schurig
<holgerschurig@gmail.com> wrote:
> 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.