Call trace observed when running xfstests on btrfs filesystem

Bug #1717443 reported by bugproxy on 2017-09-15
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
The Ubuntu-power-systems project
High
Canonical Kernel Team
linux (Ubuntu)
High
Canonical Kernel Team

Bug Description

== Comment: #0 - Harish Sriram <> - 2017-07-21 00:34:58 ==
Problem Description
----------------------------
Call trace observed when running xfstests on btrfs filesystem

Environment
------------------
Kernel Build: 4.11.0-10-generic
System Name : ltc-boston124
Model : 9006-22C
Platform : PowerNV ( P9 )

Uname output
-------------------
# uname -a
Linux ltc-boston124 4.11.0-10-generic #15-Ubuntu SMP Thu Jun 29 15:02:54 UTC 2017 ppc64le ppc64le ppc64le GNU/Linux

Steps to reproduce:
----------------------------------------
1. Create a loop device with btrfs filesystem
2. git clone git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git; cd xfstests-dev
3. make
4. Create a local.config for running with created loop device
5.. Run xfstests-dev test : ./check tests/btrfs/130

Dmesg:
----------
[Fri Jul 21 01:26:55 2017] INFO: rcu_sched self-detected stall on CPU
[Fri Jul 21 01:26:55 2017] 4-...: (210013 ticks this GP) idle=6db/140000000000001/0 softirq=18227470/18227470 fqs=104791
[Fri Jul 21 01:26:55 2017] (t=210039 jiffies g=10179019 c=10179018 q=1388)
[Fri Jul 21 01:26:55 2017] Task dump for CPU 4:
[Fri Jul 21 01:26:55 2017] btrfs R running task 0 24224 19847 0x00042006
[Fri Jul 21 01:26:55 2017] Call Trace:
[Fri Jul 21 01:26:55 2017] [c0002003dd62efb0] [c0000000001240dc] sched_show_task+0xcc/0x150 (unreliable)
[Fri Jul 21 01:26:55 2017] [c0002003dd62f020] [c000000000b80d20] rcu_dump_cpu_stacks+0xd0/0x134
[Fri Jul 21 01:26:55 2017] [c0002003dd62f070] [c000000000177214] rcu_check_callbacks+0x9f4/0xb40
[Fri Jul 21 01:26:55 2017] [c0002003dd62f1a0] [c000000000180968] update_process_times+0x48/0x90
[Fri Jul 21 01:26:55 2017] [c0002003dd62f1d0] [c000000000197a70] tick_sched_handle.isra.7+0x30/0xb0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f200] [c000000000197b54] tick_sched_timer+0x64/0xd0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f240] [c000000000181408] __hrtimer_run_queues+0x108/0x390
[Fri Jul 21 01:26:55 2017] [c0002003dd62f2c0] [c000000000182458] hrtimer_interrupt+0xf8/0x330
[Fri Jul 21 01:26:55 2017] [c0002003dd62f390] [c000000000023dcc] __timer_interrupt+0x8c/0x270
[Fri Jul 21 01:26:55 2017] [c0002003dd62f3e0] [c0000000000241cc] timer_interrupt+0x9c/0xe0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f410] [c0000000000090a4] decrementer_common+0x114/0x120
[Fri Jul 21 01:26:55 2017] --- interrupt: 901 at find_parent_nodes+0x97c/0x1680 [btrfs]
                               LR = find_parent_nodes+0x930/0x1680 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62f700] [c0080000571bcbfc] find_parent_nodes+0x874/0x1680 [btrfs] (unreliable)
[Fri Jul 21 01:26:55 2017] [c0002003dd62f840] [c0080000571bee64] iterate_extent_inodes+0x3ec/0x440 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62f960] [c0080000571ccddc] process_extent+0x804/0xc00 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fa80] [c0080000571d06cc] changed_cb+0x574/0xe00 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fb40] [c0080000571d1f74] btrfs_ioctl_send+0x101c/0x10e0 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fc40] [c008000057186218] btrfs_ioctl+0x16e0/0x23f0 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fd40] [c000000000372124] do_vfs_ioctl+0xd4/0x8c0
[Fri Jul 21 01:26:55 2017] [c0002003dd62fde0] [c0000000003729e4] SyS_ioctl+0xd4/0xf0
[Fri Jul 21 01:26:55 2017] [c0002003dd62fe30] [c00000000000b184] system_call+0x38/0xe0
[Fri Jul 21 01:27:58 2017] INFO: rcu_sched self-detected stall on CPU
[Fri Jul 21 01:27:58 2017] 4-...: (225763 ticks this GP) idle=6db/140000000000001/0 softirq=18227470/18227470 fqs=112651
[Fri Jul 21 01:27:58 2017] (t=225792 jiffies g=10179019 c=10179018 q=2542)
[Fri Jul 21 01:27:58 2017] Task dump for CPU 4:
[Fri Jul 21 01:27:58 2017] btrfs R running task 0 24224 19847 0x00042006
[Fri Jul 21 01:27:58 2017] Call Trace:
[Fri Jul 21 01:27:58 2017] [c0002003dd62efb0] [c0000000001240dc] sched_show_task+0xcc/0x150 (unreliable)
[Fri Jul 21 01:27:58 2017] [c0002003dd62f020] [c000000000b80d20] rcu_dump_cpu_stacks+0xd0/0x134
[Fri Jul 21 01:27:58 2017] [c0002003dd62f070] [c000000000177214] rcu_check_callbacks+0x9f4/0xb40
[Fri Jul 21 01:27:58 2017] [c0002003dd62f1a0] [c000000000180968] update_process_times+0x48/0x90
[Fri Jul 21 01:27:58 2017] [c0002003dd62f1d0] [c000000000197a70] tick_sched_handle.isra.7+0x30/0xb0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f200] [c000000000197b54] tick_sched_timer+0x64/0xd0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f240] [c000000000181408] __hrtimer_run_queues+0x108/0x390
[Fri Jul 21 01:27:58 2017] [c0002003dd62f2c0] [c000000000182458] hrtimer_interrupt+0xf8/0x330
[Fri Jul 21 01:27:58 2017] [c0002003dd62f390] [c000000000023dcc] __timer_interrupt+0x8c/0x270
[Fri Jul 21 01:27:58 2017] [c0002003dd62f3e0] [c0000000000241cc] timer_interrupt+0x9c/0xe0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f410] [c0000000000090a4] decrementer_common+0x114/0x120
[Fri Jul 21 01:27:58 2017] --- interrupt: 901 at find_parent_nodes+0x97c/0x1680 [btrfs]
                               LR = find_parent_nodes+0x930/0x1680 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62f700] [c0080000571bcbfc] find_parent_nodes+0x874/0x1680 [btrfs] (unreliable)
[Fri Jul 21 01:27:58 2017] [c0002003dd62f840] [c0080000571bee64] iterate_extent_inodes+0x3ec/0x440 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62f960] [c0080000571ccddc] process_extent+0x804/0xc00 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fa80] [c0080000571d06cc] changed_cb+0x574/0xe00 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fb40] [c0080000571d1f74] btrfs_ioctl_send+0x101c/0x10e0 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fc40] [c008000057186218] btrfs_ioctl+0x16e0/0x23f0 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fd40] [c000000000372124] do_vfs_ioctl+0xd4/0x8c0
[Fri Jul 21 01:27:58 2017] [c0002003dd62fde0] [c0000000003729e4] SyS_ioctl+0xd4/0xf0
[Fri Jul 21 01:27:58 2017] [c0002003dd62fe30] [c00000000000b184] system_call+0x38/0xe0

System is hung till process is killed..

== Comment: #5 - Harish Sriram <> - 2017-07-24 01:22:02 ==
Issue is reproducible on 4.13-rc2 kernel from http://kernel.ubuntu.com/~kernel-ppa/mainline/v4.13-rc2/

[ 901.860630] NMI backtrace for cpu 12
[ 901.860637] CPU: 12 PID: 21321 Comm: btrfs Not tainted 4.13.0-041300rc2-generic #201707232231
[ 901.860641] Call Trace:
[ 901.860657] [c000203965d2aeb0] [c000000000bab93c] dump_stack+0xb0/0xf4 (unreliable)
[ 901.860666] [c000203965d2aef0] [c000000000bb4a68] nmi_cpu_backtrace+0x208/0x210
[ 901.860673] [c000203965d2af80] [c000000000bb4c30] nmi_trigger_cpumask_backtrace+0x1c0/0x200
[ 901.860681] [c000203965d2b010] [c00000000002e2b8] arch_trigger_cpumask_backtrace+0x28/0x40
[ 901.860690] [c000203965d2b030] [c0000000001862f0] rcu_dump_cpu_stacks+0xf0/0x160
[ 901.860697] [c000203965d2b080] [c0000000001857d4] rcu_check_callbacks+0xa14/0xb60
[ 901.860705] [c000203965d2b1b0] [c000000000191528] update_process_times+0x48/0x90
[ 901.860713] [c000203965d2b1e0] [c0000000001a88bc] tick_sched_handle.isra.5+0x4c/0x80
[ 901.860721] [c000203965d2b200] [c0000000001a8950] tick_sched_timer+0x60/0xe0
[ 901.860728] [c000203965d2b240] [c000000000191fb8] __hrtimer_run_queues+0xf8/0x360
[ 901.860735] [c000203965d2b2c0] [c000000000192f0c] hrtimer_interrupt+0xfc/0x340
[ 901.860742] [c000203965d2b390] [c0000000000243e4] __timer_interrupt+0x94/0x270
[ 901.860750] [c000203965d2b3e0] [c000000000024804] timer_interrupt+0xa4/0xe0
[ 901.860757] [c000203965d2b410] [c000000000008f74] decrementer_common+0x114/0x120
[ 901.860858] --- interrupt: 901 at find_parent_nodes+0x97c/0x1680 [btrfs]
                   LR = find_parent_nodes+0x930/0x1680 [btrfs]
[ 901.860905] [c000203965d2b700] [c00800000fd2f6fc] find_parent_nodes+0x874/0x1680 [btrfs] (unreliable)
[ 901.860958] [c000203965d2b840] [c00800000fd31964] iterate_extent_inodes+0x3ec/0x440 [btrfs]
[ 901.861006] [c000203965d2b960] [c00800000fd4047c] process_extent+0x904/0xce0 [btrfs]
[ 901.861054] [c000203965d2ba80] [c00800000fd4357c] changed_cb+0x574/0xe00 [btrfs]
[ 901.861104] [c000203965d2bb40] [c00800000fd45548] btrfs_ioctl_send+0xea0/0x1070 [btrfs]
[ 901.861156] [c000203965d2bc40] [c00800000fcf85b8] btrfs_ioctl+0x1580/0x2470 [btrfs]
[ 901.861164] [c000203965d2bd40] [c00000000038cd74] do_vfs_ioctl+0xd4/0x8d0
[ 901.861171] [c000203965d2bde0] [c00000000038d644] SyS_ioctl+0xd4/0x130
[ 901.861179] [c000203965d2be30] [c00000000000b184] system_call+0x58/0x6c

Thanks,
Harish

== Comment: #9 - Victor Aoqui <> - 2017-09-14 14:20:32 ==
Problem Description
----------------------------
Call trace observed when running xfstests on btrfs filesystem

Environment
------------------
Kernel Build: 4.11.0-10-generic
System Name : ltc-boston124
Model : 9006-22C
Platform : PowerNV ( P9 )

Uname output
-------------------
# uname -a
Linux ltc-boston124 4.11.0-10-generic #15-Ubuntu SMP Thu Jun 29 15:02:54 UTC 2017 ppc64le ppc64le ppc64le GNU/Linux

Steps to reproduce:
----------------------------------------
1. Create a loop device with btrfs filesystem
2. git clone git://git.kernel.org/pub/scm/fs/xfs/xfstests-dev.git; cd xfstests-dev
3. make
4. Create a local.config for running with created loop device
5.. Run xfstests-dev test : ./check tests/btrfs/130

Dmesg:
----------
[Fri Jul 21 01:26:55 2017] INFO: rcu_sched self-detected stall on CPU
[Fri Jul 21 01:26:55 2017] 4-...: (210013 ticks this GP) idle=6db/140000000000001/0 softirq=18227470/18227470 fqs=104791
[Fri Jul 21 01:26:55 2017] (t=210039 jiffies g=10179019 c=10179018 q=1388)
[Fri Jul 21 01:26:55 2017] Task dump for CPU 4:
[Fri Jul 21 01:26:55 2017] btrfs R running task 0 24224 19847 0x00042006
[Fri Jul 21 01:26:55 2017] Call Trace:
[Fri Jul 21 01:26:55 2017] [c0002003dd62efb0] [c0000000001240dc] sched_show_task+0xcc/0x150 (unreliable)
[Fri Jul 21 01:26:55 2017] [c0002003dd62f020] [c000000000b80d20] rcu_dump_cpu_stacks+0xd0/0x134
[Fri Jul 21 01:26:55 2017] [c0002003dd62f070] [c000000000177214] rcu_check_callbacks+0x9f4/0xb40
[Fri Jul 21 01:26:55 2017] [c0002003dd62f1a0] [c000000000180968] update_process_times+0x48/0x90
[Fri Jul 21 01:26:55 2017] [c0002003dd62f1d0] [c000000000197a70] tick_sched_handle.isra.7+0x30/0xb0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f200] [c000000000197b54] tick_sched_timer+0x64/0xd0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f240] [c000000000181408] __hrtimer_run_queues+0x108/0x390
[Fri Jul 21 01:26:55 2017] [c0002003dd62f2c0] [c000000000182458] hrtimer_interrupt+0xf8/0x330
[Fri Jul 21 01:26:55 2017] [c0002003dd62f390] [c000000000023dcc] __timer_interrupt+0x8c/0x270
[Fri Jul 21 01:26:55 2017] [c0002003dd62f3e0] [c0000000000241cc] timer_interrupt+0x9c/0xe0
[Fri Jul 21 01:26:55 2017] [c0002003dd62f410] [c0000000000090a4] decrementer_common+0x114/0x120
[Fri Jul 21 01:26:55 2017] --- interrupt: 901 at find_parent_nodes+0x97c/0x1680 [btrfs]
                               LR = find_parent_nodes+0x930/0x1680 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62f700] [c0080000571bcbfc] find_parent_nodes+0x874/0x1680 [btrfs] (unreliable)
[Fri Jul 21 01:26:55 2017] [c0002003dd62f840] [c0080000571bee64] iterate_extent_inodes+0x3ec/0x440 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62f960] [c0080000571ccddc] process_extent+0x804/0xc00 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fa80] [c0080000571d06cc] changed_cb+0x574/0xe00 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fb40] [c0080000571d1f74] btrfs_ioctl_send+0x101c/0x10e0 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fc40] [c008000057186218] btrfs_ioctl+0x16e0/0x23f0 [btrfs]
[Fri Jul 21 01:26:55 2017] [c0002003dd62fd40] [c000000000372124] do_vfs_ioctl+0xd4/0x8c0
[Fri Jul 21 01:26:55 2017] [c0002003dd62fde0] [c0000000003729e4] SyS_ioctl+0xd4/0xf0
[Fri Jul 21 01:26:55 2017] [c0002003dd62fe30] [c00000000000b184] system_call+0x38/0xe0
[Fri Jul 21 01:27:58 2017] INFO: rcu_sched self-detected stall on CPU
[Fri Jul 21 01:27:58 2017] 4-...: (225763 ticks this GP) idle=6db/140000000000001/0 softirq=18227470/18227470 fqs=112651
[Fri Jul 21 01:27:58 2017] (t=225792 jiffies g=10179019 c=10179018 q=2542)
[Fri Jul 21 01:27:58 2017] Task dump for CPU 4:
[Fri Jul 21 01:27:58 2017] btrfs R running task 0 24224 19847 0x00042006
[Fri Jul 21 01:27:58 2017] Call Trace:
[Fri Jul 21 01:27:58 2017] [c0002003dd62efb0] [c0000000001240dc] sched_show_task+0xcc/0x150 (unreliable)
[Fri Jul 21 01:27:58 2017] [c0002003dd62f020] [c000000000b80d20] rcu_dump_cpu_stacks+0xd0/0x134
[Fri Jul 21 01:27:58 2017] [c0002003dd62f070] [c000000000177214] rcu_check_callbacks+0x9f4/0xb40
[Fri Jul 21 01:27:58 2017] [c0002003dd62f1a0] [c000000000180968] update_process_times+0x48/0x90
[Fri Jul 21 01:27:58 2017] [c0002003dd62f1d0] [c000000000197a70] tick_sched_handle.isra.7+0x30/0xb0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f200] [c000000000197b54] tick_sched_timer+0x64/0xd0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f240] [c000000000181408] __hrtimer_run_queues+0x108/0x390
[Fri Jul 21 01:27:58 2017] [c0002003dd62f2c0] [c000000000182458] hrtimer_interrupt+0xf8/0x330
[Fri Jul 21 01:27:58 2017] [c0002003dd62f390] [c000000000023dcc] __timer_interrupt+0x8c/0x270
[Fri Jul 21 01:27:58 2017] [c0002003dd62f3e0] [c0000000000241cc] timer_interrupt+0x9c/0xe0
[Fri Jul 21 01:27:58 2017] [c0002003dd62f410] [c0000000000090a4] decrementer_common+0x114/0x120
[Fri Jul 21 01:27:58 2017] --- interrupt: 901 at find_parent_nodes+0x97c/0x1680 [btrfs]
                               LR = find_parent_nodes+0x930/0x1680 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62f700] [c0080000571bcbfc] find_parent_nodes+0x874/0x1680 [btrfs] (unreliable)
[Fri Jul 21 01:27:58 2017] [c0002003dd62f840] [c0080000571bee64] iterate_extent_inodes+0x3ec/0x440 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62f960] [c0080000571ccddc] process_extent+0x804/0xc00 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fa80] [c0080000571d06cc] changed_cb+0x574/0xe00 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fb40] [c0080000571d1f74] btrfs_ioctl_send+0x101c/0x10e0 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fc40] [c008000057186218] btrfs_ioctl+0x16e0/0x23f0 [btrfs]
[Fri Jul 21 01:27:58 2017] [c0002003dd62fd40] [c000000000372124] do_vfs_ioctl+0xd4/0x8c0
[Fri Jul 21 01:27:58 2017] [c0002003dd62fde0] [c0000000003729e4] SyS_ioctl+0xd4/0xf0
[Fri Jul 21 01:27:58 2017] [c0002003dd62fe30] [c00000000000b184] system_call+0x38/0xe0

System is hung till process is killed..

bugproxy (bugproxy) wrote : sosreport

Default Comment by Bridge

tags: added: architecture-ppc64le bugnameltc-156897 severity-high targetmilestone-inin---
Changed in ubuntu:
assignee: nobody → Ubuntu on IBM Power Systems Bug Triage (ubuntu-power-triage)
affects: ubuntu → linux (Ubuntu)
Changed in ubuntu-power-systems:
importance: Undecided → High
assignee: nobody → Canonical Kernel Team (canonical-kernel-team)
Joseph Salisbury (jsalisbury) wrote :

Did this issue start happening after an update/upgrade? Was there a prior kernel version where you were not having this particular problem?

Would it be possible for you to test the latest upstream kernel? Refer to https://wiki.ubuntu.com/KernelMainlineBuilds . Please test the latest v4.14 kernel[0].

If this bug is fixed in the mainline kernel, please add the following tag 'kernel-fixed-upstream'.

If the mainline kernel does not fix this bug, please add the tag: 'kernel-bug-exists-upstream'.

Once testing of the upstream kernel is complete, please mark this bug as "Confirmed".

Thanks in advance.

[0] http://kernel.ubuntu.com/~kernel-ppa/mainline/v4.14-rc1/

Changed in linux (Ubuntu):
importance: Undecided → High
status: New → Incomplete
Changed in ubuntu-power-systems:
status: New → Incomplete
tags: added: kernel-da-key
Manoj Iyer (manjo) on 2017-09-25
Changed in linux (Ubuntu):
assignee: Ubuntu on IBM Power Systems Bug Triage (ubuntu-power-triage) → Canonical Kernel Team (canonical-kernel-team)
tags: added: triage-g
Po-Hsu Lin (cypressyew) wrote :

Similar bug 1718925

Po-Hsu Lin (cypressyew) wrote :

Hello Harish,

This test is known to be buggy, and is suggested to be skipped from upstream [1].
And with our colleague Colin's investigation suggests the same action too.

Therefore I will mark this bug as invalid.

Thank you.

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

Changed in ubuntu-power-systems:
status: Incomplete → Invalid
Changed in linux (Ubuntu):
status: Incomplete → Invalid
bugproxy (bugproxy) on 2017-11-29
tags: added: targetmilestone-inin1710
removed: targetmilestone-inin---
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Bug attachments