On Sun, Dec 11, 2016 at 5:12 PM, Markus Binsteiner <mak...@gmail.com> wrote:
>> You might try 'btrfs check' without repairing, using a recent version
>> of btrfs-progs and see if it finds anything unusual.
>
> Not quite sure what that output means, but btrfs check returns instantly:
>
> $ sudo btrfs check /dev/mapper/think--big-home
> Checking filesystem on /dev/mapper/think--big-home
> UUID: 7f1ce0ed-5986-43ae-b0dd-727eee19fd08
> checking extents
> checking free space cache
> checking fs roots
> checking csums
> checking root refs
> found 655360 bytes used err is 0
> total csum bytes: 0
> total tree bytes: 131072
> total fs tree bytes: 32768
> total extent tree bytes: 16384
> btree space waste bytes: 123528
> file data blocks allocated: 524288
> referenced 524288
This is what I'd expect if the volume has only had a mkfs done and
then mounted and umounted. No files. What do you get for
btrfs ins dump-s -fa /dev/mapper/think--big-home
>
> When I do the same thing on the root-OS partition that is on the same
> disk, it takes a bit longer to complete, and I'm getting:
>
> $ sudo btrfs check /dev/mapper/think--big-jessie
> Checking filesystem on /dev/mapper/think--big-jessie
> UUID: d82e2746-4164-41fa-b528-5a5838d818c6
> checking extents
> checking free space cache
> checking fs roots
> checking csums
> checking root refs
> found 29295181824 bytes used err is 0
> total csum bytes: 27623652
> total tree bytes: 973848576
> total fs tree bytes: 874446848
> total extent tree bytes: 62554112
> btree space waste bytes: 154131992
> file data blocks allocated: 29202391040
> referenced 30898016256
>
> So I reckon the tree(s) in my home partition is just empty? Why would
> btrfs-find-tree take so long to complete though?
Looks like a bug. I'm not sure when this regression began, but I see
it with btrfs-progs-4.8.5-1.fc26.x86_64 on a new file system, with no
files and also one volume that has a single file. But it's not hanging
on older file systems.
# btrfs-find-root /dev/mapper/vg-test2
Superblock thinks the generation is 8
Superblock thinks the level is 0
Indefinite hang.
>Also, I've tried to
> run btrfs-find-tree on the root-OS partition, but that also didn't
> complete within the 10 minutes I tried (so far).
Yeah same here, but unlike your case it completes fast for older file
systems with a decent amount of data on it. I'm not sure what the
pattern is here that results in the hang. Unfortunately strace is not
revealing I think - attached anyway.
--
Chris Murphy
root@f25h ~]# strace btrfs-find-root /dev/mapper/vg-test2
execve("/sbin/btrfs-find-root", ["btrfs-find-root", "/dev/mapper/vg-test2"],
[/* 31 vars */]) = 0
brk(NULL) = 0x5571d01f7000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f389a106000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=99038, ...}) = 0
mmap(NULL, 99038, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f389a0ed000
close(3) = 0
open("/lib64/libuuid.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\24\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=19528, ...}) = 0
mmap(NULL, 2113552, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f3899cde000
mprotect(0x7f3899ce2000, 2093056, PROT_NONE) = 0
mmap(0x7f3899ee1000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3000) = 0x7f3899ee1000
mmap(0x7f3899ee2000, 16, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f3899ee2000
close(3) = 0
open("/lib64/libblkid.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`\206\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=275520, ...}) = 0
mmap(NULL, 2368448, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f3899a9b000
mprotect(0x7f3899ad8000, 2097152, PROT_NONE) = 0
mmap(0x7f3899cd8000, 20480, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3d000) = 0x7f3899cd8000
mmap(0x7f3899cdd000, 960, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f3899cdd000
close(3) = 0
open("/lib64/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0` \0\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=89520, ...}) = 0
mmap(NULL, 2183272, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f3899885000
mprotect(0x7f389989a000, 2093056, PROT_NONE) = 0
mmap(0x7f3899a99000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14000) = 0x7f3899a99000
close(3) = 0
open("/lib64/liblzo2.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@%\0\0\0\0\0\0"..., 832)
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=142312, ...}) = 0
mmap(NULL, 2236424, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f3899662000
mprotect(0x7f3899684000, 2093056, PROT_NONE) = 0
mmap(0x7f3899883000, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x21000) = 0x7f3899883000
mmap(0x7f3899884000, 8, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f3899884000
close(3) = 0
open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240`\0\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=151112, ...}) = 0
mmap(NULL, 2217000, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f3899444000
mprotect(0x7f389945c000, 2097152, PROT_NONE) = 0
mmap(0x7f389965c000, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x7f389965c000
mmap(0x7f389965e000, 13352, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f389965e000
close(3) = 0
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \5\2\0\0\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=2115832, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f389a0eb000
mmap(NULL, 3955040, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
0x7f389907e000
mprotect(0x7f389923b000, 2093056, PROT_NONE) = 0
mmap(0x7f389943a000, 24576, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bc000) = 0x7f389943a000
mmap(0x7f3899440000, 14688, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f3899440000
close(3) = 0
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f389a0e8000
arch_prctl(ARCH_SET_FS, 0x7f389a0e88c0) = 0
mprotect(0x7f389943a000, 16384, PROT_READ) = 0
mprotect(0x7f389965c000, 4096, PROT_READ) = 0
mprotect(0x7f3899883000, 4096, PROT_READ) = 0
mprotect(0x7f3899a99000, 4096, PROT_READ) = 0
mprotect(0x7f3899ee1000, 4096, PROT_READ) = 0
mprotect(0x7f3899cd8000, 16384, PROT_READ) = 0
mprotect(0x5571cfab4000, 8192, PROT_READ) = 0
mprotect(0x7f389a108000, 4096, PROT_READ) = 0
munmap(0x7f389a0ed000, 99038) = 0
set_tid_address(0x7f389a0e8b90) = 3952
set_robust_list(0x7f389a0e8ba0, 24) = 0
rt_sigaction(SIGRTMIN, {0x7f3899449b40, [], SA_RESTORER|SA_SIGINFO,
0x7f38994555c0}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x7f3899449bd0, [], SA_RESTORER|SA_RESTART|SA_SIGINFO,
0x7f38994555c0}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
stat("/dev/mapper/vg-test2", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 7),
...}) = 0
open("/dev/mapper/vg-test2", O_RDONLY) = 3
fadvise64(3, 0, 0, POSIX_FADV_DONTNEED) = 0
brk(NULL) = 0x5571d01f7000
brk(0x5571d0218000) = 0x5571d0218000
brk(NULL) = 0x5571d0218000
lseek(3, 0, SEEK_END) = 268435456000
lseek(3, 0, SEEK_SET) = 0
pread64(3,
"\231d\4\244\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"..., 4096,
65536) = 4096
open("/dev/mapper/vg-test2", O_RDONLY) = 4
fadvise64(4, 0, 0, POSIX_FADV_DONTNEED) = 0
pread64(3,
"\231d\4\244\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"..., 4096,
65536) = 4096
pread64(4,
"s+\260t\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"..., 16384,
147456) = 16384
pread64(4,
"\335X/*\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"..., 16384,
21151744) = 16384
pread64(4,
"'\353m\16\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"..., 16384,
21168128) = 16384
pread64(4,
">%\2348\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"..., 16384,
21135360) = 16384
pread64(4,
"\240{\227\366\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"...,
16384, 21184512) = 16384
pread64(4,
"O\224,/\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"..., 16384,
21004288) = 16384
close(3) = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 1), ...}) = 0
write(1, "Superblock thinks the generation"..., 39Superblock thinks the
generation is 10
) = 39
write(1, "Superblock thinks the level is 0"..., 33Superblock thinks the level
is 0
) = 33
^C--- SIGINT {si_signo=SIGINT, si_code=SI_KERNEL} ---
strace: Process 3952 detached
[root@f25h ~]#
