btrfs/130 test causing soft lockup and rcu_sched self-detected stall on CPU

Bug #1718925 reported by Po-Hsu Lin
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Invalid
Medium
Unassigned

Bug Description

This issue was found by the regression test suite.
This test will hang and get killed with our timeout setting.

It's not a regression as I can see that it will time out on older kernels as well. And it can be seen on different releases (although I haven't check if they all have the same dmesg output)

The stalled process will hinder the test for xfs filesystem. As the partition was occupied and cannot be destroyed.

There is a similar bug 1717443

[ 215.728801] BTRFS: device fsid 97eb2b12-1ed4-4cab-bdb8-de78292ab2d1 devid 1 transid 3 /dev/sdb2
[ 215.808560] BTRFS info (device sdb2): disk space caching is enabled
[ 215.808564] BTRFS: has skinny extents
[ 215.808566] BTRFS: flagging fs with big metadata feature
[ 215.922083] BTRFS: creating UUID tree
[ 216.295453] BTRFS: device fsid 18dbdc70-b4a8-4a1d-bd6e-629a7c44c769 devid 1 transid 3 /dev/sdb2
[ 216.374891] BTRFS info (device sdb2): disk space caching is enabled
[ 216.374894] BTRFS: has skinny extents
[ 216.374896] BTRFS: flagging fs with big metadata feature
[ 216.397006] BTRFS: creating UUID tree
[ 222.588433] perf interrupt took too long (3642 > 2500), lowering kernel.perf_event_max_sample_rate to 50000
[ 256.078072] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [btrfs:12947]
[ 256.078507] Modules linked in: ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 256.078570] CPU: 0 PID: 12947 Comm: btrfs Not tainted 4.4.0-96-generic #119-Ubuntu
[ 256.078573] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 256.078576] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 256.078579] RIP: 0010:[<ffffffffc0289504>] [<ffffffffc0289504>] find_parent_nodes+0x5c4/0x7a0 [btrfs]
[ 256.078618] RSP: 0018:ffff880859eef928 EFLAGS: 00000282
[ 256.078620] RAX: ffff88083fb29c40 RBX: 0000000000000000 RCX: ffff880859eef970
[ 256.078623] RDX: ffff88083fb29c20 RSI: 0000000001c78000 RDI: ffff880854561000
[ 256.078625] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 0000000180330021
[ 256.078627] R10: ffff88083fc6f5a0 R11: 000000000001a890 R12: ffff880854561000
[ 256.078628] R13: ffff88083fc6f500 R14: 0000000000000000 R15: ffff880859eefa50
[ 256.078632] FS: 00007f52288698c0(0000) GS:ffff88085f200000(0000) knlGS:0000000000000000
[ 256.078634] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 256.078636] CR2: 00007f52277ebe38 CR3: 00000008547cd000 CR4: 00000000003406f0
[ 256.078638] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 256.078640] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 256.078642] Stack:
[ 256.078644] 0000000000000000 ffff88085b318000 0000000000000000 ffff880854561000
[ 256.078648] ffff880859eefa50 0000000000c40000 0000000000000000 ffff8808592091b0
[ 256.078652] 00000000592093f0 ffff8808580e5ce0 0000000000001063 ffff880859eef980
[ 256.078656] Call Trace:
[ 256.078683] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 256.078706] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 256.078726] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 256.078747] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 256.078767] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 256.078786] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 256.078805] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 256.078828] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 256.078833] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 256.078839] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 256.078842] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 256.078846] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 256.078850] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 256.078854] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 256.078859] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 256.078863] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 256.078867] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 256.078872] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 256.078875] Code: a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 48 89 c2 48 8b 42 10 <48> 85 c0 75 f4 49 8b 45 38 48 89 42 10 48 c7 85 78 ff ff ff 00
[ 284.077090] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [btrfs:12947]
[ 284.077530] Modules linked in: ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 284.077589] CPU: 0 PID: 12947 Comm: btrfs Tainted: G L 4.4.0-96-generic #119-Ubuntu
[ 284.077591] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 284.077594] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 284.077596] RIP: 0010:[<ffffffffc02894fd>] [<ffffffffc02894fd>] find_parent_nodes+0x5bd/0x7a0 [btrfs]
[ 284.077634] RSP: 0018:ffff880859eef928 EFLAGS: 00000286
[ 284.077636] RAX: ffff88083b22d200 RBX: 0000000000000000 RCX: ffff880859eef970
[ 284.077638] RDX: ffff88083b22d1e0 RSI: 0000000001ca8000 RDI: ffff880854561000
[ 284.077640] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 0000000180330020
[ 284.077641] R10: ffff88083fd1b780 R11: 000000000001a890 R12: ffff880854561000
[ 284.077643] R13: ffff88083fd1b6e0 R14: 0000000000000000 R15: ffff880859eefa50
[ 284.077646] FS: 00007f52288698c0(0000) GS:ffff88085f200000(0000) knlGS:0000000000000000
[ 284.077648] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 284.077650] CR2: 00007f52277ebe38 CR3: 00000008547cd000 CR4: 00000000003406f0
[ 284.077652] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 284.077654] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 284.077655] Stack:
[ 284.077657] 0000000000000000 ffff88085b318000 0000000000000000 ffff880854561000
[ 284.077661] ffff880859eefa50 0000000000c40000 0000000000000000 ffff8808592091b0
[ 284.077664] 00000000592093f0 ffff880850c898e0 0000000000001063 ffff880859eef980
[ 284.077668] Call Trace:
[ 284.077693] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 284.077715] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 284.077734] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 284.077753] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 284.077772] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 284.077789] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 284.077807] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 284.077828] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 284.077833] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 284.077839] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 284.077842] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 284.077845] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 284.077849] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 284.077853] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 284.077857] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 284.077861] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 284.077864] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 284.077870] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 284.077872] Code: 00 85 c0 89 c3 0f 88 a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 <48> 89 c2 48 8b 42 10 48 85 c0 75 f4 49 8b 45 38 48 89 42 10 48
[ 291.864815] INFO: rcu_sched self-detected stall on CPU
[ 291.865136] 0-...: (14999 ticks this GP) idle=037/140000000000001/0 softirq=6826/6826 fqs=14986
[ 291.865666] (t=15000 jiffies g=5255 c=5254 q=462)
[ 291.865966] Task dump for CPU 0:
[ 291.865969] btrfs R running task 0 12947 8601 0x00000008
[ 291.865974] ffff880858118e00 7d3693218f1b3cab ffff88085f203da8 ffffffff810aedd9
[ 291.865978] 0000000000000000 ffffffff81e52e00 ffff88085f203dc0 ffffffff810b16b7
[ 291.865981] 0000000000000001 ffff88085f203df0 ffffffff810e527e ffff88085f217b80
[ 291.865984] Call Trace:
[ 291.865987] <IRQ> [<ffffffff810aedd9>] sched_show_task+0xa9/0x110
[ 291.866000] [<ffffffff810b16b7>] dump_cpu_task+0x37/0x40
[ 291.866005] [<ffffffff810e527e>] rcu_dump_cpu_stacks+0x8e/0xe0
[ 291.866009] [<ffffffff810e901a>] rcu_check_callbacks+0x4fa/0x7f0
[ 291.866016] [<ffffffff81140d1c>] ? acct_account_cputime+0x1c/0x20
[ 291.866020] [<ffffffff810b215f>] ? account_system_time+0x7f/0x110
[ 291.866025] [<ffffffff810ff300>] ? tick_sched_handle.isra.14+0x60/0x60
[ 291.866029] [<ffffffff810ef5c9>] update_process_times+0x39/0x60
[ 291.866032] [<ffffffff810ff2c5>] tick_sched_handle.isra.14+0x25/0x60
[ 291.866036] [<ffffffff810ff33d>] tick_sched_timer+0x3d/0x70
[ 291.866039] [<ffffffff810eff02>] __hrtimer_run_queues+0x102/0x290
[ 291.866042] [<ffffffff810f06c8>] hrtimer_interrupt+0xa8/0x1a0
[ 291.866048] [<ffffffff81053078>] local_apic_timer_interrupt+0x38/0x60
[ 291.866053] [<ffffffff81845d1d>] smp_apic_timer_interrupt+0x3d/0x50
[ 291.866059] [<ffffffff81843fe2>] apic_timer_interrupt+0x82/0x90
[ 291.866061] <EOI> [<ffffffffc0289504>] ? find_parent_nodes+0x5c4/0x7a0 [btrfs]
[ 291.866113] [<ffffffffc02894d3>] ? find_parent_nodes+0x593/0x7a0 [btrfs]
[ 291.866134] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 291.866154] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 291.866171] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 291.866190] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 291.866208] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 291.866225] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 291.866243] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 291.866264] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 291.866268] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 291.866273] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 291.866276] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 291.866279] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 291.866283] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 291.866286] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 291.866291] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 291.866295] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 291.866298] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 291.866302] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 316.075965] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [btrfs:12947]
[ 316.076407] Modules linked in: ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 316.076465] CPU: 0 PID: 12947 Comm: btrfs Tainted: G L 4.4.0-96-generic #119-Ubuntu
[ 316.076468] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 316.076471] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 316.076473] RIP: 0010:[<ffffffffc02894fd>] [<ffffffffc02894fd>] find_parent_nodes+0x5bd/0x7a0 [btrfs]
[ 316.076510] RSP: 0018:ffff880859eef928 EFLAGS: 00000286
[ 316.076512] RAX: ffff880022d2a0a0 RBX: 0000000000000000 RCX: ffff880859eef970
[ 316.076514] RDX: ffff880022d2a080 RSI: 0000000001c78000 RDI: ffff880854561000
[ 316.076515] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 0000000180330014
[ 316.076517] R10: ffff88083fd9f9b0 R11: 000000000001a890 R12: ffff880854561000
[ 316.076519] R13: ffff88083fd9f910 R14: 0000000000000000 R15: ffff880859eefa50
[ 316.076522] FS: 00007f52288698c0(0000) GS:ffff88085f200000(0000) knlGS:0000000000000000
[ 316.076524] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 316.076526] CR2: 00007f52277ebe38 CR3: 00000008547cd000 CR4: 00000000003406f0
[ 316.076528] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 316.076530] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 316.076531] Stack:
[ 316.076533] 0000000000000000 ffff88085b318000 0000000000000000 ffff880854561000
[ 316.076537] ffff880859eefa50 0000000000c40000 0000000000000000 ffff8808592091b0
[ 316.076540] 00000000592093f0 ffff8808580e5ce0 0000000000001063 ffff880859eef980
[ 316.076544] Call Trace:
[ 316.076568] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 316.076589] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 316.076609] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 316.076628] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 316.076646] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 316.076663] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 316.076681] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 316.076702] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 316.076707] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 316.076713] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 316.076716] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 316.076719] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 316.076723] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 316.076727] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 316.076731] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 316.076735] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 316.076738] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 316.076744] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 316.076746] Code: 00 85 c0 89 c3 0f 88 a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 <48> 89 c2 48 8b 42 10 48 85 c0 75 f4 49 8b 45 38 48 89 42 10 48
[ 319.350180] perf interrupt took too long (5787 > 5000), lowering kernel.perf_event_max_sample_rate to 25000
[ 332.110571] cfg80211: World regulatory domain updated:
[ 332.110576] cfg80211: DFS Master region: unset
[ 332.110578] cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[ 332.110581] cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 332.110584] cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[ 332.110586] cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[ 332.110589] cfg80211: (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[ 332.110592] cfg80211: (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[ 332.110594] cfg80211: (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[ 332.110596] cfg80211: (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[ 332.110599] cfg80211: (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[ 364.122273] NMI watchdog: BUG: soft lockup - CPU#12 stuck for 23s! [btrfs:12947]
[ 364.122716] Modules linked in: cfg80211 ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 364.122777] CPU: 12 PID: 12947 Comm: btrfs Tainted: G L 4.4.0-96-generic #119-Ubuntu
[ 364.122779] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 364.122782] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 364.122785] RIP: 0010:[<ffffffffc02894fd>] [<ffffffffc02894fd>] find_parent_nodes+0x5bd/0x7a0 [btrfs]
[ 364.122822] RSP: 0018:ffff880859eef928 EFLAGS: 00000282
[ 364.122824] RAX: ffff8800224c3c80 RBX: 0000000000000000 RCX: ffff880859eef970
[ 364.122826] RDX: ffff8800224c3c60 RSI: 0000000001c9c000 RDI: ffff8808500aff00
[ 364.122828] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 0000000180330012
[ 364.122830] R10: ffff88083414eaa0 R11: 000000000001a890 R12: ffff8808500aff00
[ 364.122831] R13: ffff88083414ea00 R14: 0000000000000000 R15: ffff880859eefa50
[ 364.122834] FS: 00007f52288698c0(0000) GS:ffff88085f500000(0000) knlGS:0000000000000000
[ 364.122836] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 364.122838] CR2: 00007fdd1abdc0e0 CR3: 00000008547cd000 CR4: 00000000003406e0
[ 364.122840] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 364.122842] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 364.122844] Stack:
[ 364.122845] 0000000000000000 ffff88085b318000 0000000000000000 ffff8808500aff00
[ 364.122849] ffff880859eefa50 0000000000c40000 0000000000000000 ffff88085928ed80
[ 364.122853] 000000005928ecf0 ffff880857ad5600 0000000000001063 ffff880859eef980
[ 364.122856] Call Trace:
[ 364.122881] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 364.122902] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 364.122920] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 364.122939] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 364.122957] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 364.122975] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 364.122992] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 364.123013] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 364.123019] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 364.123025] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 364.123028] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 364.123031] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 364.123036] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 364.123040] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 364.123045] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 364.123049] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 364.123052] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 364.123058] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 364.123060] Code: 00 85 c0 89 c3 0f 88 a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 <48> 89 c2 48 8b 42 10 48 85 c0 75 f4 49 8b 45 38 48 89 42 10 48
[ 392.121285] NMI watchdog: BUG: soft lockup - CPU#12 stuck for 23s! [btrfs:12947]
[ 392.121744] Modules linked in: cfg80211 ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 392.121802] CPU: 12 PID: 12947 Comm: btrfs Tainted: G L 4.4.0-96-generic #119-Ubuntu
[ 392.121805] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 392.121808] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 392.121810] RIP: 0010:[<ffffffffc0289504>] [<ffffffffc0289504>] find_parent_nodes+0x5c4/0x7a0 [btrfs]
[ 392.121846] RSP: 0018:ffff880859eef928 EFLAGS: 00000286
[ 392.121848] RAX: ffff880837b461e0 RBX: 0000000000000000 RCX: ffff880859eef970
[ 392.121850] RDX: ffff880837b461c0 RSI: 0000000001c9c000 RDI: ffff8808500aff00
[ 392.121852] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 000000018033000f
[ 392.121853] R10: ffff880834185dc0 R11: 000000000001a890 R12: ffff8808500aff00
[ 392.121855] R13: ffff880834185d20 R14: 0000000000000000 R15: ffff880859eefa50
[ 392.121858] FS: 00007f52288698c0(0000) GS:ffff88085f500000(0000) knlGS:0000000000000000
[ 392.121860] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 392.121862] CR2: 00007fdd1abdc0e0 CR3: 00000008547cd000 CR4: 00000000003406e0
[ 392.121864] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 392.121866] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 392.121867] Stack:
[ 392.121869] 0000000000000000 ffff88085b318000 0000000000000000 ffff8808500aff00
[ 392.121873] ffff880859eefa50 0000000000c40000 0000000000000000 ffff88085928ed80
[ 392.121876] 000000005928ecf0 ffff880857ad5600 0000000000001063 ffff880859eef980
[ 392.121880] Call Trace:
[ 392.121905] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 392.121925] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 392.121944] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 392.121963] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 392.121981] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 392.121999] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 392.122017] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 392.122039] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 392.122044] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 392.122050] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 392.122053] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 392.122056] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 392.122060] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 392.122064] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 392.122069] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 392.122073] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 392.122076] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 392.122081] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 392.122083] Code: a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 48 89 c2 48 8b 42 10 <48> 85 c0 75 f4 49 8b 45 38 48 89 42 10 48 c7 85 78 ff ff ff 00
[ 399.409025] INFO: rcu_sched self-detected stall on CPU
[ 399.410066] 12-...: (14999 ticks this GP) idle=fe5/140000000000001/0 softirq=4506/4506 fqs=14998
[ 399.410907] (t=15000 jiffies g=5362 c=5361 q=333)
[ 399.411226] Task dump for CPU 12:
[ 399.411229] btrfs R running task 0 12947 8601 0x00000008
[ 399.411233] ffff880858118e00 7d3693218f1b3cab ffff88085f503da8 ffffffff810aedd9
[ 399.411237] 000000000000000c ffffffff81e52e00 ffff88085f503dc0 ffffffff810b16b7
[ 399.411240] 000000000000000d ffff88085f503df0 ffffffff810e527e ffff88085f517b80
[ 399.411244] Call Trace:
[ 399.411246] <IRQ> [<ffffffff810aedd9>] sched_show_task+0xa9/0x110
[ 399.411260] [<ffffffff810b16b7>] dump_cpu_task+0x37/0x40
[ 399.411265] [<ffffffff810e527e>] rcu_dump_cpu_stacks+0x8e/0xe0
[ 399.411268] [<ffffffff810e901a>] rcu_check_callbacks+0x4fa/0x7f0
[ 399.411275] [<ffffffff81140d1c>] ? acct_account_cputime+0x1c/0x20
[ 399.411280] [<ffffffff810b215f>] ? account_system_time+0x7f/0x110
[ 399.411285] [<ffffffff810ff300>] ? tick_sched_handle.isra.14+0x60/0x60
[ 399.411289] [<ffffffff810ef5c9>] update_process_times+0x39/0x60
[ 399.411292] [<ffffffff810ff2c5>] tick_sched_handle.isra.14+0x25/0x60
[ 399.411296] [<ffffffff810ff33d>] tick_sched_timer+0x3d/0x70
[ 399.411300] [<ffffffff810eff02>] __hrtimer_run_queues+0x102/0x290
[ 399.411303] [<ffffffff810f06c8>] hrtimer_interrupt+0xa8/0x1a0
[ 399.411308] [<ffffffff81053078>] local_apic_timer_interrupt+0x38/0x60
[ 399.411314] [<ffffffff81845d1d>] smp_apic_timer_interrupt+0x3d/0x50
[ 399.411319] [<ffffffff81843fe2>] apic_timer_interrupt+0x82/0x90
[ 399.411321] <EOI> [<ffffffffc0289500>] ? find_parent_nodes+0x5c0/0x7a0 [btrfs]
[ 399.411377] [<ffffffffc02894d3>] ? find_parent_nodes+0x593/0x7a0 [btrfs]
[ 399.411397] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 399.411417] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 399.411435] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 399.411454] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 399.411472] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 399.411489] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 399.411507] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 399.411528] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 399.411531] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 399.411536] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 399.411539] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 399.411542] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 399.411545] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 399.411549] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 399.411554] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 399.411558] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 399.411561] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 399.411566] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 424.120155] NMI watchdog: BUG: soft lockup - CPU#12 stuck for 22s! [btrfs:12947]
[ 424.120588] Modules linked in: cfg80211 ipmi_ssif intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass sb_edac edac_core hpilo 8250_fintek ipmi_si ipmi_msghandler lpc_ich shpchp acpi_power_meter ioatdma dca mac_hid ib_iser rdma_cm iw_cm ib_cm ib_sa ib_mad ib_core ib_addr iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi autofs4 btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq libcrc32c raid1 raid0 multipath linear crct10dif_pclmul crc32_pclmul ghash_clmulni_intel ses enclosure aesni_intel aes_x86_64 lrw gf128mul glue_helper ablk_helper cryptd tg3 ptp pps_core hpsa scsi_transport_sas wmi fjes
[ 424.120648] CPU: 12 PID: 12947 Comm: btrfs Tainted: G L 4.4.0-96-generic #119-Ubuntu
[ 424.120650] Hardware name: HP ProLiant DL360 Gen9/ProLiant DL360 Gen9, BIOS P89 12/27/2015
[ 424.120653] task: ffff880858118e00 ti: ffff880859eec000 task.ti: ffff880859eec000
[ 424.120655] RIP: 0010:[<ffffffffc0289504>] [<ffffffffc0289504>] find_parent_nodes+0x5c4/0x7a0 [btrfs]
[ 424.120692] RSP: 0018:ffff880859eef928 EFLAGS: 00000282
[ 424.120694] RAX: ffff880835ae5ea0 RBX: 0000000000000000 RCX: ffff880859eef970
[ 424.120696] RDX: ffff880835ae5e80 RSI: 0000000001cac000 RDI: ffff8808500aff00
[ 424.120698] RBP: ffff880859eef9f8 R08: 0000000002400040 R09: 0000000180330031
[ 424.120700] R10: ffff880078187410 R11: 000000000001a890 R12: ffff8808500aff00
[ 424.120702] R13: ffff880078187370 R14: 0000000000000000 R15: ffff880859eefa50
[ 424.120704] FS: 00007f52288698c0(0000) GS:ffff88085f500000(0000) knlGS:0000000000000000
[ 424.120706] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 424.120708] CR2: 00007fdd1abdc0e0 CR3: 00000008547cd000 CR4: 00000000003406e0
[ 424.120710] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 424.120712] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 424.120714] Stack:
[ 424.120715] 0000000000000000 ffff88085b318000 0000000000000000 ffff8808500aff00
[ 424.120719] ffff880859eefa50 0000000000c40000 0000000000000000 ffff88085928ed80
[ 424.120723] 000000005928ecf0 ffff8808555f7400 0000000000001063 ffff880859eef980
[ 424.120726] Call Trace:
[ 424.120750] [<ffffffffc02911d0>] ? dir_changed.isra.15+0xa0/0xa0 [btrfs]
[ 424.120771] [<ffffffffc028a3c9>] iterate_extent_inodes+0x109/0x350 [btrfs]
[ 424.120790] [<ffffffffc028a018>] ? extent_from_logical+0x198/0x230 [btrfs]
[ 424.120809] [<ffffffffc0295aa1>] process_extent+0x771/0x1000 [btrfs]
[ 424.120827] [<ffffffffc0292960>] ? __record_deleted_ref+0x30/0x30 [btrfs]
[ 424.120845] [<ffffffffc0297021>] changed_cb+0x231/0xad0 [btrfs]
[ 424.120862] [<ffffffffc02989f4>] btrfs_ioctl_send+0x1134/0x1210 [btrfs]
[ 424.120883] [<ffffffffc025f083>] btrfs_ioctl+0x2a3/0x28b0 [btrfs]
[ 424.120889] [<ffffffff810b4e67>] ? task_move_group_fair+0x57/0x60
[ 424.120895] [<ffffffff810b2d6c>] ? __enqueue_entity+0x6c/0x70
[ 424.120898] [<ffffffff810b8937>] ? enqueue_entity+0x3a7/0xd10
[ 424.120901] [<ffffffff810b934a>] ? enqueue_task_fair+0xaa/0x8b0
[ 424.120905] [<ffffffff81037ef9>] ? sched_clock+0x9/0x10
[ 424.120909] [<ffffffff810b1d9f>] ? sched_clock_cpu+0x8f/0xa0
[ 424.120914] [<ffffffff81223faf>] do_vfs_ioctl+0x29f/0x490
[ 424.120918] [<ffffffff8108061c>] ? _do_fork+0xec/0x360
[ 424.120921] [<ffffffff81224219>] SyS_ioctl+0x79/0x90
[ 424.120927] [<ffffffff81843272>] entry_SYSCALL_64_fastpath+0x16/0x71
[ 424.120928] Code: a8 01 00 00 75 32 48 8b 85 78 ff ff ff 48 85 c0 0f 84 a2 01 00 00 48 8b 50 10 48 85 d2 75 08 e9 96 01 00 00 48 89 c2 48 8b 42 10 <48> 85 c0 75 f4 49 8b 45 38 48 89 42 10 48 c7 85 78 ff ff ff 00

ProblemType: Bug
DistroRelease: Ubuntu 16.04
Package: linux-image-4.4.0-96-generic 4.4.0-96.119
ProcVersionSignature: User Name 4.4.0-96.119-generic 4.4.83
Uname: Linux 4.4.0-96-generic x86_64
AlsaDevices:
 total 0
 crw-rw---- 1 root audio 116, 1 Sep 22 11:37 seq
 crw-rw---- 1 root audio 116, 33 Sep 22 11:37 timer
AplayDevices: Error: [Errno 2] No such file or directory: 'aplay'
ApportVersion: 2.20.1-0ubuntu2.10
Architecture: amd64
ArecordDevices: Error: [Errno 2] No such file or directory: 'arecord'
AudioDevicesInUse: Error: command ['fuser', '-v', '/dev/snd/seq', '/dev/snd/timer'] failed with exit code 1:
Date: Fri Sep 22 11:43:07 2017
IwConfig: Error: [Errno 2] No such file or directory: 'iwconfig'
MachineType: HP ProLiant DL360 Gen9
PciMultimedia:

ProcEnviron:
 TERM=xterm-256color
 PATH=(custom, no user)
 XDG_RUNTIME_DIR=<set>
 LANG=en_US.UTF-8
 SHELL=/bin/bash
ProcFB: 0 EFI VGA
ProcKernelCmdLine: BOOT_IMAGE=/boot/vmlinuz-4.4.0-96-generic root=UUID=051b34ce-dfed-4e36-aa78-851c5a284ee4 ro
RelatedPackageVersions:
 linux-restricted-modules-4.4.0-96-generic N/A
 linux-backports-modules-4.4.0-96-generic N/A
 linux-firmware 1.157.12
RfKill: Error: [Errno 2] No such file or directory: 'rfkill'
SourcePackage: linux
UpgradeStatus: No upgrade log present (probably fresh install)
dmi.bios.date: 12/27/2015
dmi.bios.vendor: HP
dmi.bios.version: P89
dmi.board.name: ProLiant DL360 Gen9
dmi.board.vendor: HP
dmi.chassis.type: 23
dmi.chassis.vendor: HP
dmi.modalias: dmi:bvnHP:bvrP89:bd12/27/2015:svnHP:pnProLiantDL360Gen9:pvr:rvnHP:rnProLiantDL360Gen9:rvr:cvnHP:ct23:cvr:
dmi.product.name: ProLiant DL360 Gen9
dmi.sys.vendor: HP

Revision history for this message
Po-Hsu Lin (cypressyew) wrote :
Revision history for this message
Ubuntu Kernel Bot (ubuntu-kernel-bot) wrote : Status changed to Confirmed

This change was made by a bot.

Changed in linux (Ubuntu):
status: New → Confirmed
Changed in linux (Ubuntu):
importance: Undecided → Medium
tags: added: kernel-da-key
Revision history for this message
Po-Hsu Lin (cypressyew) wrote :

As suggested by upstream [1], we have this test disabled in the xfstest test suite.

Therefore I will mark this bug as Invalid.

[1] https://<email address hidden>/msg69094.html

Changed in linux (Ubuntu):
status: Confirmed → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.