Bug ID 975966
Summary hang in FITRIM ioctl()
Classification openSUSE
Product openSUSE Tumbleweed
Version Current
Hardware x86-64
OS Other
Status CONFIRMED
Severity Normal
Priority P5 - None
Component Kernel
Assignee kernel-maintainers@forge.provo.novell.com
Reporter sbrabec@suse.com
QA Contact qa-bugs@suse.de
Found By ---
Blocker ---

While installing util-linux-systemd by online update tool, rpm hangs.

Linux oct 4.5.0-3-default #1 SMP PREEMPT Mon Mar 28 07:27:57 UTC 2016 (8cf0ce6)
x86_64 x86_64 x86_64 GNU/Linux

Analyzing the problem, I found that the hang is caused by:

        ������packagekitd���������btrfs-defrag-pl
        ���             ������rpm���������sh���������sh���������systemctl

The hanging systemctl is:
/usr/bin/systemctl try-restart fstrim.service fstrim.timer

And the hanging command is:

ps axl shows:
4     0  5777     1  20   0  22252  2556 blkdev Ds   ?          0:11
/usr/sbin/fstrim -a

# ls -al /proc/5777/fd/
total 0
dr-x------ 2 root root  0 Apr 18 14:40 .
dr-xr-xr-x 9 root root  0 Apr 18 13:59 ..
lr-x------ 1 root root 64 Apr 18 14:40 0 -> /dev/null
lrwx------ 1 root root 64 Apr 18 14:40 1 -> socket:[101297]
lrwx------ 1 root root 64 Apr 18 14:40 2 -> socket:[101297]
lr-x------ 1 root root 64 Apr 18 14:40 3 ->
/sys/devices/pci0000:00/0000:00:1f.2/ata3/host2/target2:0:0/2:0:0:0/block/sdb
lr-x------ 1 root root 64 Apr 18 14:40 4 -> /boot/grub2/i386-pc


/dev/sdb is this device:

[    2.274041] scsi 2:0:0:0: Direct-Access     ATA      KINGSTON SV300S3 BBF0
PQ: 0 ANSI: 5
[    2.275099] sd 0:0:0:0: [sda] Attached SCSI disk
[    2.304981] sd 2:0:0:0: [sdb] 468862128 512-byte logical blocks: (240 GB/224
GiB)
[    2.305504] sd 2:0:0:0: [sdb] Write Protect is off
[    2.305511] sd 2:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[    2.305806] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled,
doesn't support DPO or FUA
[    2.306629]  sdb: sdb1 sdb2
[    2.307319] sd 2:0:0:0: [sdb] Attached SCSI disk

There are no error or timeout messages in dmesg, only this one:
[ 1110.897517] perf interrupt took too long (2509 > 2500), lowering
kernel.perf_event_max_sample_rate to 50000


oct:~ # cat /proc/5777/stack 
[<ffffffff8136f950>] blkdev_issue_discard+0x1e0/0x230
[<ffffffffa03d7161>] btrfs_issue_discard+0xe1/0x180 [btrfs]
[<ffffffffa03ddc4c>] btrfs_discard_extent+0x9c/0x100 [btrfs]
[<ffffffffa043dfc4>] do_trimming+0xa4/0x170 [btrfs]
[<ffffffffa043fbac>] btrfs_trim_block_group+0x4bc/0x540 [btrfs]
[<ffffffffa03e8e6a>] btrfs_trim_fs+0x10a/0x3f0 [btrfs]
[<ffffffffa042b41e>] btrfs_ioctl_fitrim+0x11e/0x170 [btrfs]
[<ffffffffa0431d0f>] btrfs_ioctl+0x4cf/0x1e30 [btrfs]
[<ffffffff8121dd02>] do_vfs_ioctl+0x92/0x580
[<ffffffff8121e269>] SyS_ioctl+0x79/0x90
[<ffffffff816cc072>] entry_SYSCALL_64_fastpath+0x16/0x71
[<ffffffffffffffff>] 0xffffffffffffffff

gdb disassemble (with a debuginfo from release 3.1) indicates that it waits in
wait_for_completion_io().

   0xffffffff8136f93f <+463>:    lock decl 0x20(%rsp)
   0xffffffff8136f944 <+468>:    je     0xffffffff8136f950
<blkdev_issue_discard+480>
   0xffffffff8136f946 <+470>:    lea    0x30(%rsp),%rdi
   0xffffffff8136f94b <+475>:    callq  0xffffffff816c8630
<wait_for_completion_io>
-> 0xffffffff8136f950 <+480>:    mov    0x24(%rsp),%eax
   0xffffffff8136f954 <+484>:    test   %eax,%eax
   0xffffffff8136f956 <+486>:    cmove  %ebx,%eax
   0xffffffff8136f959 <+489>:    lea    -0x28(%rbp),%rsp



Strace hangs for long minutes, then it does few commands and hangs again:

strace: Process 5777 attached
close(4)                                = 0
stat("/boot/grub2/x86_64-efi", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
stat("/boot/grub2", {st_mode=S_IFDIR|0755, st_size=168, ...}) = 0
stat("/dev/sdb1", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 17), ...}) = 0
open("/sys/dev/block/8:17", O_RDONLY|O_CLOEXEC) = 4
newfstatat(4, "partition", {st_mode=S_IFREG|0444, st_size=4096, ...}, 0) = 0
readlink("/sys/dev/block/8:17", "../../devices/pci0000:00/0000:00"..., 4095) =
83
open("/sys/block/sdb/dev", O_RDONLY|O_CLOEXEC) = 5
fstat(5, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f8fc2425000
read(5, "8:16\n", 4096)                 = 5
close(5)                                = 0
munmap(0x7f8fc2425000, 4096)            = 0
close(4)                                = 0
open("/sys/dev/block/8:17", O_RDONLY|O_CLOEXEC) = 4
openat(4, "queue/discard_granularity", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such
file or directory)
openat(3, "queue/discard_granularity", O_RDONLY|O_CLOEXEC) = 5
fcntl(5, F_GETFL)                       = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(5, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f8fc2425000
read(5, "512\n", 4096)                  = 4
close(5)                                = 0
munmap(0x7f8fc2425000, 4096)            = 0
close(4)                                = 0
open("/boot/grub2/x86_64-efi", O_RDONLY) = 4
fstat(4, {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
ioctl(4, FITRIM, {start=0, len=0xffffffffffffffff, minlen=0}


You are receiving this mail because: