Re: mkfs.f2fs gets stuck with "blk_update_request: bio idx 0 >= vcnt0" on 3.8

From: Max Filippov
Date: Mon Apr 01 2013 - 16:21:30 EST

On 04/01/2013 11:27 PM, Vyacheslav Dubeyko wrote:
>
> On Apr 1, 2013, at 9:19 PM, Max Filippov wrote:
>
>> Hi,
>>
>> I'm trying to create f2fs filesystem on SD card on pandaboard using
>> f2fs-tools v1.0.0.
>> It works fine on Linus' v3.6, but fails on both v3.8 and stable v3.8.5:
>>
>> # mkfs.f2fs /dev/mmcblk0p3
>> Info: sector size = 512
>> Info: total sectors = 11370496 (in 512bytes)
>> Info: zone aligned segment0 blkaddr: 512
>> [ 257.789764] blk_update_request: bio idx 0 >= vcnt 0
>>
>> mkfs process gets stuck in D state and I see the following in the dmesg:
>>
>> [ 257.789733] __end_that: dev mmcblk0: type=1, flags=122c8081
>> [ 257.789764] sector 4194304, nr/cnr 2981888/4294959104
>> [ 257.789764] bio df3840c0, biotail df3848c0, buffer (null), len 1526726656
>> [ 257.789764] blk_update_request: bio idx 0 >= vcnt 0
>> [ 257.794921] request botched: dev mmcblk0: type=1, flags=122c8081
>> [ 257.794921] sector 4194304, nr/cnr 2981888/4294959104
>> [ 257.794921] bio df3840c0, biotail df3848c0, buffer (null), len 1526726656
>>
>> I'd appreciate any suggestion on what to try before I try to bisect it.
>>
>
> Could you share "cat /proc/partitions" and "strace mkfs.f2fs /dev/mmcblk0p3" outputs? I think that these outputs can be very useful for issue analysis.
>
> By the way, can you reproduce the issue on another SD-card? Do you reproduce the issue only under pandaboard?

Yes, I can reproduce it on three SD cards of different vendors and different sizes.
Unfortunately ATM I don't have any other board to try it on.

# cat /proc/partitions
major minor #blocks name

179 0 7782400 mmcblk0
179 1 40131 mmcblk0p1
179 2 32130 mmcblk0p2
179 3 5685248 mmcblk0p3

strace output is the following:

execve("/home/jcmvbkbc/opt/bin/mkfs.f2fs", ["mkfs.f2fs", "/dev/mmcblk0p3"], [/* 17 vars */]) = 0
brk(0) = 0x15000
uname({sys="Linux", node="zoo.metropolis", ...}) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f39000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=15792, ...}) = 0
mmap2(NULL, 15792, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb6f35000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/arm-linux-gnueabihf/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\340%\0\0004\0\0\0"..., 512) = 512
lseek(3, 33324, SEEK_SET) = 33324
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1120) = 1120
lseek(3, 32988, SEEK_SET) = 32988
read(3, "A6\0\0\0aeabi\0\1,\0\0\0\0057-A\0\6\n\7A\10\1\t\2\n\4\22"..., 55) = 55
fstat64(3, {st_mode=S_IFREG|0644, st_size=34444, ...}) = 0
mmap2(NULL, 65812, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6f0c000
mprotect(0xb6f14000, 28672, PROT_NONE) = 0
mmap2(0xb6f1b000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7) = 0xb6f1b000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/arm-linux-gnueabihf/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\355p\1\0004\0\0\0"..., 512) = 512
lseek(3, 888764, SEEK_SET) = 888764
read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1360) = 1360
lseek(3, 888324, SEEK_SET) = 888324
read(3, "A4\0\0\0aeabi\0\1*\0\0\0\0057-A\0\6\n\7A\10\1\t\2\n\4\22"..., 53) = 53
fstat64(3, {st_mode=S_IFREG|0755, st_size=890124, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f34000
mmap2(NULL, 931200, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb6e28000
mprotect(0xb6efe000, 32768, PROT_NONE) = 0
mmap2(0xb6f06000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xd6) = 0xb6f06000
mmap2(0xb6f09000, 9600, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb6f09000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6e27000
set_tls(0xb6e274c0, 0xb6e27b98, 0xb6f3c048, 0xb6e274c0, 0xb6f34570) = 0
mprotect(0xb6f06000, 8192, PROT_READ) = 0
mprotect(0xb6f1b000, 4096, PROT_READ) = 0
mprotect(0x13000, 4096, PROT_READ) = 0
mprotect(0xb6f3b000, 4096, PROT_READ) = 0
munmap(0xb6f35000, 15792) = 0
brk(0) = 0x15000
brk(0x36000) = 0x36000
open("/etc/mtab", O_RDONLY|O_CLOEXEC) = 3
fcntl64(3, F_GETFD) = 0x1 (flags FD_CLOEXEC)
fstat64(3, {st_mode=S_IFREG|0644, st_size=506, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f38000
read(3, "192.168.0.1:/tftpboot/zoo/panda_"..., 4096) = 506
read(3, "", 4096) = 0
close(3) = 0
munmap(0xb6f38000, 4096) = 0
open("/dev/mmcblk0p3", O_RDWR) = 3
fstat64(3, {st_mode=S_IFBLK|0660, st_rdev=makedev(179, 3), ...}) = 0
ioctl(3, BLKSSZGET, 0xbeffc27c) = 0
ioctl(3, BLKGETSIZE, 0x140d8) = 0
ioctl(3, 0x301, 0xbeffc274) = 0
fstat64(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 2), ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb6f38000
write(1, "Info: sector size = 512\n", 24) = 24
write(1, "Info: total sectors = 11370496 ("..., 45) = 45
write(1, "Info: zone aligned segment0 blka"..., 41) = 41
fstat64(3, {st_mode=S_IFBLK|0660, st_rdev=makedev(179, 3), ...}) = 0
ioctl(3, BLKDISCARD


--
Thanks.
-- Max
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/