* possible irq lock inversion dependency detected
@ 2017-10-10 18:51 René van Dorst
2017-10-11 1:19 ` Jason A. Donenfeld
0 siblings, 1 reply; 7+ messages in thread
From: René van Dorst @ 2017-10-10 18:51 UTC (permalink / raw)
To: wireguard
Hi Jason,
I got a "possible irq lock inversion dependency detected" while
shutdown a active tunnel with "wg-quick down wg0".
Linux utilite 4.13.5 #15 SMP Tue Oct 10 12:22:12 CEST 2017 armv7l GNU/Linux
WireGuard 0.0.20171005-4-g5101cb7
Distro: Debian 9.2 stretch armhf.
The kernel and wireguard compiled from source on the device.
Device: IMX6q Utilite Pro.
Dmesg log:
[12352.549306] wireguard: wg0: Peer 1 (192.168.2.222:36464) destroyed
[12352.550905] ========================================================
[12352.557311] WARNING: possible irq lock inversion dependency detected
[12352.563721] 4.13.5 #15 Tainted: G O
[12352.568380] --------------------------------------------------------
[12352.574785] swapper/0/0 just changed the state of lock:
[12352.580054] (&(&r->consumer_lock)->rlock){+.-...}, at:
[<bf0400ac>] packet_queue_free+0x24/0x84 [wireguard]
[12352.590096] but this lock took another, SOFTIRQ-unsafe lock in the past:
[12352.596851] (&syncp->seq#7){+.+...}
[12352.596888]
and interrupts could create inverse lock ordering between them.
[12352.611967]
other info that might help us debug this:
[12352.618591] Possible interrupt unsafe locking scenario:
[12352.625461] CPU0 CPU1
[12352.630043] ---- ----
[12352.634623] lock(&syncp->seq#7);
[12352.638095] local_irq_disable();
[12352.644073]
lock(&(&r->consumer_lock)->rlock);
[12352.651286] lock(&syncp->seq#7);
[12352.657238] <Interrupt>
[12352.659873] lock(&(&r->consumer_lock)->rlock);
[12352.664688]
*** DEADLOCK ***
[12352.670643] 1 lock held by swapper/0/0:
[12352.674496] #0: (rcu_callback){......}, at: [<c0188f90>]
rcu_process_callbacks+0x2fc/0x5d0
[12352.682991]
the shortest dependencies between 2nd lock and 1st lock:
[12352.690854] -> (&syncp->seq#7){+.+...} ops: 427590 {
[12352.695944] HARDIRQ-ON-W at:
[12352.699200] lock_acquire+0x70/0x90
[12352.704541] iptunnel_xmit+0x174/0x1e0
[12352.710140] udp_tunnel_xmit_skb+0xe8/0xf0
[12352.716121]
socket_send_skb_to_peer+0x400/0x830 [wireguard]
[12352.723665]
socket_send_buffer_to_peer+0x74/0x84 [wireguard]
[12352.731292]
packet_send_handshake_initiation+0xb8/0xf8 [wireguard]
[12352.739437]
packet_handshake_send_worker+0x18/0x24 [wireguard]
[12352.747217] process_one_work+0x24c/0x4e8
[12352.753074] worker_thread+0x40/0x574
[12352.758583] kthread+0x120/0x160
[12352.763659] ret_from_fork+0x14/0x24
[12352.769079] SOFTIRQ-ON-W at:
[12352.772333] lock_acquire+0x70/0x90
[12352.777699]
receive_handshake_packet+0x114/0x3f0 [wireguard]
[12352.785325]
packet_handshake_receive_worker+0x1c/0x44 [wireguard]
[12352.793364] process_one_work+0x24c/0x4e8
[12352.799220] worker_thread+0x40/0x574
[12352.804728] kthread+0x120/0x160
[12352.809802] ret_from_fork+0x14/0x24
[12352.815223] INITIAL USE at:
[12352.818388] lock_acquire+0x70/0x90
[12352.823638] ip_tunnel_get_stats64+0x148/0x190
[12352.829848] dev_get_stats+0x40/0xb4
[12352.835188] rtnl_fill_stats+0x38/0x120
[12352.840784] rtnl_fill_ifinfo+0x508/0xe00
[12352.846555] rtmsg_ifinfo_build_skb+0x70/0xe0
[12352.852673] rtmsg_ifinfo_event.part.7+0x1c/0x4c
[12352.859052] rtmsg_ifinfo+0x30/0x38
[12352.864302] __dev_notify_flags+0x94/0xa4
[12352.870071] rtnl_configure_link+0x80/0xa4
[12352.875928] rtnl_newlink+0x64c/0x748
[12352.881349] rtnetlink_rcv_msg+0x94/0x1f4
[12352.887122] netlink_rcv_skb+0xe0/0x100
[12352.892716] rtnetlink_rcv+0x28/0x38
[12352.898049] netlink_unicast+0x184/0x26c
[12352.903730] netlink_sendmsg+0x29c/0x378
[12352.909417] sock_sendmsg+0x1c/0x2c
[12352.914664] ___sys_sendmsg+0x214/0x22c
[12352.920260] __sys_sendmsg+0x48/0x74
[12352.925594] SyS_sendmsg+0x10/0x14
[12352.930757] ret_fast_syscall+0x0/0x1c
[12352.936262] }
[12352.938062] ... key at: [<bf05e5b8>]
__key.33453+0x0/0xffffba48 [wireguard]
[12352.945664] ... acquired at:
[12352.948738] iptunnel_xmit+0x174/0x1e0
[12352.952683] udp_tunnel_xmit_skb+0xe8/0xf0
[12352.957000] socket_send_skb_to_peer+0x400/0x830 [wireguard]
[12352.962880] packet_tx_worker+0xc8/0x3e4 [wireguard]
[12352.968043] process_one_work+0x24c/0x4e8
[12352.972248] worker_thread+0x40/0x574
[12352.976101] kthread+0x120/0x160
[12352.979522] ret_from_fork+0x14/0x24
[12352.984790] -> (&(&r->consumer_lock)->rlock){+.-...} ops: 139059 {
[12352.991012] HARDIRQ-ON-W at:
[12352.994180] lock_acquire+0x70/0x90
[12352.999351] _raw_spin_lock_bh+0x4c/0x5c
[12353.004976] packet_encrypt_worker+0x2c/0x574
[wireguard]
[12353.012054] process_one_work+0x24c/0x4e8
[12353.017736] worker_thread+0x40/0x574
[12353.023069] kthread+0x120/0x160
[12353.027971] ret_from_fork+0x14/0x24
[12353.033215] IN-SOFTIRQ-W at:
[12353.036380] lock_acquire+0x70/0x90
[12353.041542] _raw_spin_lock_bh+0x4c/0x5c
[12353.047166] packet_queue_free+0x24/0x84 [wireguard]
[12353.053830] rcu_release+0x48/0x6c [wireguard]
[12353.059949] rcu_process_callbacks+0x338/0x5d0
[12353.066072] __do_softirq+0xf0/0x2a0
[12353.071318] irq_exit+0xe8/0x160
[12353.076222] __handle_domain_irq+0x60/0xc0
[12353.081991] gic_handle_irq+0x64/0xc4
[12353.087326] __irq_svc+0x70/0x98
[12353.092227] cpuidle_enter_state+0x188/0x2b0
[12353.098169] cpuidle_enter+0x1c/0x20
[12353.103418] call_cpuidle+0x28/0x44
[12353.108578] do_idle+0x10c/0x1e0
[12353.113476] cpu_startup_entry+0x20/0x24
[12353.119072] rest_init+0x228/0x278
[12353.124151] start_kernel+0x32c/0x3a0
[12353.129485] 0x8000807c
[12353.133597] INITIAL USE at:
[12353.136676] lock_acquire+0x70/0x90
[12353.141751] _raw_spin_lock_bh+0x4c/0x5c
[12353.147289] packet_encrypt_worker+0x2c/0x574 [wireguard]
[12353.154280] process_one_work+0x24c/0x4e8
[12353.159876] worker_thread+0x40/0x574
[12353.165122] kthread+0x120/0x160
[12353.169935] ret_from_fork+0x14/0x24
[12353.175092] }
[12353.176800] ... key at: [<bf05e640>]
__key.48712+0x0/0xffffb9c0 [wireguard]
[12353.184311] ... acquired at:
[12353.187301] mark_lock+0x2f8/0x6f0
[12353.190897] __lock_acquire+0x590/0x18e0
[12353.195013] lock_acquire+0x70/0x90
[12353.198696] _raw_spin_lock_bh+0x4c/0x5c
[12353.202837] packet_queue_free+0x24/0x84 [wireguard]
[12353.208020] rcu_release+0x48/0x6c [wireguard]
[12353.212660] rcu_process_callbacks+0x338/0x5d0
[12353.217302] __do_softirq+0xf0/0x2a0
[12353.221069] irq_exit+0xe8/0x160
[12353.224491] __handle_domain_irq+0x60/0xc0
[12353.228779] gic_handle_irq+0x64/0xc4
[12353.232633] __irq_svc+0x70/0x98
[12353.236053] cpuidle_enter_state+0x188/0x2b0
[12353.240515] cpuidle_enter+0x1c/0x20
[12353.244283] call_cpuidle+0x28/0x44
[12353.247963] do_idle+0x10c/0x1e0
[12353.251382] cpu_startup_entry+0x20/0x24
[12353.255496] rest_init+0x228/0x278
[12353.259092] start_kernel+0x32c/0x3a0
[12353.262947] 0x8000807c
[12353.267082]
stack backtrace:
[12353.271468] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G O
4.13.5 #15
[12353.278719] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
[12353.285270] Backtrace:
[12353.287749] [<c010c3b8>] (dump_backtrace) from [<c010c664>]
(show_stack+0x18/0x1c)
[12353.295353] r7:00000000 r6:600f0193 r5:00000000 r4:c0e69ce0
[12353.301047] [<c010c64c>] (show_stack) from [<c090f858>]
(dump_stack+0xb4/0xe8)
[12353.308307] [<c090f7a4>] (dump_stack) from [<c016c974>]
(print_irq_inversion_bug+0x1a0/0x214)
[12353.316868] r9:00000004 r8:00000000 r7:c0e9cc9c r6:c0e0a840
r5:c0e9cc9c r4:c0e01bdc
[12353.324649] [<c016c7d4>] (print_irq_inversion_bug) from
[<c016ca98>] (check_usage_forwards+0xb0/0x120)
[12353.333992] r9:00000004 r8:00000001 r7:c0bbca14 r6:c0e0a840
r5:00000006 r4:c0e0ad60
[12353.341771] [<c016c9e8>] (check_usage_forwards) from [<c016d96c>]
(mark_lock+0x2f8/0x6f0)
[12353.349981] r8:c0a028e4 r7:c016c9e8 r6:c0e0a840 r5:00000004 r4:c0e0ad60
[12353.356713] [<c016d674>] (mark_lock) from [<c016e8d8>]
(__lock_acquire+0x590/0x18e0)
[12353.364490] r10:c0e0a840 r9:c0e1df7c r8:00000024 r7:c163a298
r6:00000001 r5:c0e0ad60
[12353.372352] r4:00000411
[12353.374906] [<c016e348>] (__lock_acquire) from [<c01703d8>]
(lock_acquire+0x70/0x90)
[12353.382683] r10:0000000a r9:c0e132dc r8:00000001 r7:00000001
r6:600f0113 r5:00000000
[12353.390543] r4:ffffe000
[12353.393100] [<c0170368>] (lock_acquire) from [<c092b03c>]
(_raw_spin_lock_bh+0x4c/0x5c)
[12353.401138] r8:bf03ecc8 r7:c0e01da8 r6:cbd7b920 r5:bf0400ac r4:caf14988
[12353.407903] [<c092aff0>] (_raw_spin_lock_bh) from [<bf0400ac>]
(packet_queue_free+0x24/0x84 [wireguard])
[12353.417419] r5:caf14988 r4:caf14940
[12353.421064] [<bf040088>] (packet_queue_free [wireguard]) from
[<bf03ed10>] (rcu_release+0x48/0x6c [wireguard])
[12353.431101] r5:caf14808 r4:caf14e38
[12353.434722] [<bf03ecc8>] (rcu_release [wireguard]) from
[<c0188fcc>] (rcu_process_callbacks+0x338/0x5d0)
[12353.444239] r5:caf14e38 r4:cbd7b900
[12353.447841] [<c0188c94>] (rcu_process_callbacks) from [<c012a080>]
(__do_softirq+0xf0/0x2a0)
[12353.456315] r10:00000100 r9:c0e020a0 r8:c0e020a4 r7:00000009
r6:c0e00000 r5:40000001
[12353.464175] r4:00000000
[12353.466729] [<c0129f90>] (__do_softirq) from [<c012a5dc>]
(irq_exit+0xe8/0x160)
[12353.474070] r10:f4000100 r9:c0e1e1e4 r8:cb808400 r7:00000001
r6:00000000 r5:00000000
[12353.481930] r4:c0d53c18
[12353.484484] [<c012a4f4>] (irq_exit) from [<c0179794>]
(__handle_domain_irq+0x60/0xc0)
[12353.492351] [<c0179734>] (__handle_domain_irq) from [<c01014fc>]
(gic_handle_irq+0x64/0xc4)
[12353.500736] r9:c0e1e1e4 r8:c0e01ea8 r7:00000000 r6:000003ff
r5:000003eb r4:f400010c
[12353.508512] [<c0101498>] (gic_handle_irq) from [<c010d230>]
(__irq_svc+0x70/0x98)
[12353.516025] Exception stack(0xc0e01ea8 to 0xc0e01ef0)
[12353.521101] 1ea0: 00000001 00000001 00000000
c0e0a840 00000000 cbd7a4e0
[12353.529313] 1ec0: 0d4e4248 00000b3c 0cba1c80 00000b3c 00000000
c0e01f24 c0e01ec8 c0e01ef8
[12353.537521] 1ee0: c016df00 c0650398 200f0013 ffffffff
[12353.542597] r10:00000000 r9:c0e00000 r8:0cba1c80 r7:c0e01edc
r6:ffffffff r5:200f0013
[12353.550457] r4:c0650398
[12353.553012] [<c0650210>] (cpuidle_enter_state) from [<c0650500>]
(cpuidle_enter+0x1c/0x20)
[12353.561309] r10:c0e01f48 r9:c0e0d1fc r8:c0d534d8 r7:cbd7a4e0
r6:c0e0756c r5:c0e075b8
[12353.569170] r4:c0e00000 r3:cbd7a4e0
[12353.572768] [<c06504e4>] (cpuidle_enter) from [<c0165de8>]
(call_cpuidle+0x28/0x44)
[12353.580460] [<c0165dc0>] (call_cpuidle) from [<c0166008>]
(do_idle+0x10c/0x1e0)
[12353.587803] [<c0165efc>] (do_idle) from [<c0166464>]
(cpu_startup_entry+0x20/0x24)
[12353.595406] r10:c0d3da48 r9:cbfff980 r8:c0e6d000 r7:c0e07540
r6:c0e6d000 r5:00000002
[12353.603266] r4:000000bb r3:c0d4c31c
[12353.606864] [<c0166444>] (cpu_startup_entry) from [<c0923564>]
(rest_init+0x228/0x278)
[12353.614821] [<c092333c>] (rest_init) from [<c0d00cd4>]
(start_kernel+0x32c/0x3a0)
[12353.622336] r5:ffffffff r4:c0e6d04c
[12353.625934] [<c0d009a8>] (start_kernel) from [<8000807c>] (0x8000807c)
[12353.769106] wireguard: wg0: Interface deleted
root@utilite:/usr/src/WireGuard# gcc -v
Using built-in specs.
COLLECT_GCC=gcc
COLLECT_LTO_WRAPPER=/usr/lib/gcc/arm-linux-gnueabihf/6/lto-wrapper
Target: arm-linux-gnueabihf
Configured with: ../src/configure -v --with-pkgversion='Debian
6.3.0-18' --with-bugurl=file:///usr/share/doc/gcc-6/README.Bugs
--enable-languages=c,ada,c++,java,go,d,fortran,objc,obj-c++
--prefix=/usr --program-suffix=-6
--program-prefix=arm-linux-gnueabihf- --enable-shared
--enable-linker-build-id --libexecdir=/usr/lib
--without-included-gettext --enable-threads=posix --libdir=/usr/lib
--enable-nls --with-sysroot=/ --enable-clocale=gnu
--enable-libstdcxx-debug --enable-libstdcxx-time=yes
--with-default-libstdcxx-abi=new --enable-gnu-unique-object
--disable-libitm --disable-libquadmath --enable-plugin
--enable-default-pie --with-system-zlib --disable-browser-plugin
--enable-java-awt=gtk --enable-gtk-cairo
--with-java-home=/usr/lib/jvm/java-1.5.0-gcj-6-armhf/jre
--enable-java-home
--with-jvm-root-dir=/usr/lib/jvm/java-1.5.0-gcj-6-armhf
--with-jvm-jar-dir=/usr/lib/jvm-exports/java-1.5.0-gcj-6-armhf
--with-arch-directory=arm
--with-ecj-jar=/usr/share/java/eclipse-ecj.jar
--with-target-system-zlib --enable-objc-gc=auto --enable-multiarch
--disable-sjlj-exceptions --with-arch=armv7-a --with-fpu=vfpv3-d16
--with-float=hard --with-mode=thumb --enable-checking=release
--build=arm-linux-gnueabihf --host=arm-linux-gnueabihf
--target=arm-linux-gnueabihf
Thread model: posix
gcc version 6.3.0 20170516 (Debian 6.3.0-18)
root@utilite:/usr/src/WireGuard# lscpu
Architecture: armv7l
Byte Order: Little Endian
CPU(s): 4
On-line CPU(s) list: 0-3
Thread(s) per core: 1
Core(s) per socket: 4
Socket(s): 1
Model: 10
Model name: ARMv7 Processor rev 10 (v7l)
CPU max MHz: 996.0000
CPU min MHz: 396.0000
BogoMIPS: 3.00
Flags: half thumb fastmult vfp edsp neon vfpv3 tls vfpd32
Greats,
René van Dorst.
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: possible irq lock inversion dependency detected
2017-10-10 18:51 possible irq lock inversion dependency detected René van Dorst
@ 2017-10-11 1:19 ` Jason A. Donenfeld
2017-10-11 12:49 ` René van Dorst
0 siblings, 1 reply; 7+ messages in thread
From: Jason A. Donenfeld @ 2017-10-11 1:19 UTC (permalink / raw)
To: René van Dorst; +Cc: WireGuard mailing list
Hi Ren=C3=A9,
Are you able to reliably reproduce this? If so, could you let me know
if this patch fixes it?
https://git.zx2c4.com/WireGuard/patch/?id=3D940317ee52d020fc3e19e3a9f615acb=
c715985d5
Jason
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: possible irq lock inversion dependency detected
2017-10-11 1:19 ` Jason A. Donenfeld
@ 2017-10-11 12:49 ` René van Dorst
2017-10-11 12:51 ` Jason A. Donenfeld
0 siblings, 1 reply; 7+ messages in thread
From: René van Dorst @ 2017-10-11 12:49 UTC (permalink / raw)
To: Jason A. Donenfeld; +Cc: WireGuard mailing list
Quoting "Jason A. Donenfeld" <Jason@zx2c4.com>:
> Hi René,
>
> Are you able to reliably reproduce this? If so, could you let me know
> if this patch fixes it?
>
> https://git.zx2c4.com/WireGuard/patch/?id=940317ee52d020fc3e19e3a9f615acbc715985d5
>
> Jason
Hi Jason,
I am not able to reproduce it but it found a other one, hit it 3 times.
Occurs also while closing a tunnel.
Last bug was 3x reproduce after every reboot and running 'wg-quick up
wg0 && iperf3 -Z -c 10.0.0.1 && wg-quick down wg0'.
So I am not sure if you patch works or not.
Because it was not that easy to reproduce the last one.
DMESG first:
[Wed Oct 11 09:48:35 2017] wireguard: wg0: Peer 1
(192.168.2.222:36464) destroyed
[Wed Oct 11 09:48:35 2017]
========================================================
[Wed Oct 11 09:48:35 2017] WARNING: possible irq lock inversion
dependency detected
[Wed Oct 11 09:48:35 2017] 4.13.5-dirty #16 Tainted: G O
[Wed Oct 11 09:48:35 2017]
--------------------------------------------------------
[Wed Oct 11 09:48:35 2017] swapper/3/0 just changed the state of lock:
[Wed Oct 11 09:48:35 2017] (&(&r->consumer_lock)->rlock){+.-...}, at:
[<bf1350ac>] packet_queue_free+0x24/0x84 [wireguard]
[Wed Oct 11 09:48:35 2017] but this lock took another, SOFTIRQ-unsafe
lock in the past:
[Wed Oct 11 09:48:35 2017] (&syncp->seq#7){+.+...}
[Wed Oct 11 09:48:35 2017]
and interrupts could create inverse lock
ordering between them.
[Wed Oct 11 09:48:35 2017]
other info that might help us debug this:
[Wed Oct 11 09:48:35 2017] Possible interrupt unsafe locking scenario:
[Wed Oct 11 09:48:35 2017] CPU0 CPU1
[Wed Oct 11 09:48:35 2017] ---- ----
[Wed Oct 11 09:48:35 2017] lock(&syncp->seq#7);
[Wed Oct 11 09:48:35 2017] local_irq_disable();
[Wed Oct 11 09:48:35 2017]
lock(&(&r->consumer_lock)->rlock);
[Wed Oct 11 09:48:35 2017] lock(&syncp->seq#7);
[Wed Oct 11 09:48:35 2017] <Interrupt>
[Wed Oct 11 09:48:35 2017] lock(&(&r->consumer_lock)->rlock);
[Wed Oct 11 09:48:35 2017]
*** DEADLOCK ***
[Wed Oct 11 09:48:35 2017] 1 lock held by swapper/3/0:
[Wed Oct 11 09:48:35 2017] #0: (rcu_callback){......}, at:
[<c0188e90>] rcu_process_callbacks+0x2fc/0x5d0
[Wed Oct 11 09:48:35 2017]
the shortest dependencies between 2nd
lock and 1st lock:
[Wed Oct 11 09:48:35 2017] -> (&syncp->seq#7){+.+...} ops: 419515 {
[Wed Oct 11 09:48:35 2017] HARDIRQ-ON-W at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017] iptunnel_xmit+0x174/0x1e0
[Wed Oct 11 09:48:35 2017] udp_tunnel_xmit_skb+0xe8/0xf0
[Wed Oct 11 09:48:35 2017]
socket_send_skb_to_peer+0x400/0x830 [wireguard]
[Wed Oct 11 09:48:35 2017]
socket_send_buffer_to_peer+0x74/0x84 [wireguard]
[Wed Oct 11 09:48:35 2017]
packet_send_handshake_initiation+0xb8/0xf8 [wireguard]
[Wed Oct 11 09:48:35 2017]
packet_handshake_send_worker+0x18/0x24 [wireguard]
[Wed Oct 11 09:48:35 2017] process_one_work+0x24c/0x4e8
[Wed Oct 11 09:48:35 2017] worker_thread+0x40/0x574
[Wed Oct 11 09:48:35 2017] kthread+0x120/0x160
[Wed Oct 11 09:48:35 2017] ret_from_fork+0x14/0x24
[Wed Oct 11 09:48:35 2017] SOFTIRQ-ON-W at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017]
receive_handshake_packet+0x114/0x3f0 [wireguard]
[Wed Oct 11 09:48:35 2017]
packet_handshake_receive_worker+0x1c/0x44 [wireguard]
[Wed Oct 11 09:48:35 2017] process_one_work+0x24c/0x4e8
[Wed Oct 11 09:48:35 2017] worker_thread+0x40/0x574
[Wed Oct 11 09:48:35 2017] kthread+0x120/0x160
[Wed Oct 11 09:48:35 2017] ret_from_fork+0x14/0x24
[Wed Oct 11 09:48:35 2017] INITIAL USE at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017]
ip_tunnel_get_stats64+0x148/0x190
[Wed Oct 11 09:48:35 2017] dev_get_stats+0x40/0xb4
[Wed Oct 11 09:48:35 2017] rtnl_fill_stats+0x38/0x120
[Wed Oct 11 09:48:35 2017] rtnl_fill_ifinfo+0x508/0xe00
[Wed Oct 11 09:48:35 2017]
rtmsg_ifinfo_build_skb+0x70/0xe0
[Wed Oct 11 09:48:35 2017]
rtmsg_ifinfo_event.part.7+0x1c/0x4c
[Wed Oct 11 09:48:35 2017] rtmsg_ifinfo+0x30/0x38
[Wed Oct 11 09:48:35 2017] __dev_notify_flags+0x94/0xa4
[Wed Oct 11 09:48:35 2017] rtnl_configure_link+0x80/0xa4
[Wed Oct 11 09:48:35 2017] rtnl_newlink+0x64c/0x748
[Wed Oct 11 09:48:35 2017] rtnetlink_rcv_msg+0x94/0x1f4
[Wed Oct 11 09:48:35 2017] netlink_rcv_skb+0xe0/0x100
[Wed Oct 11 09:48:35 2017] rtnetlink_rcv+0x28/0x38
[Wed Oct 11 09:48:35 2017] netlink_unicast+0x184/0x26c
[Wed Oct 11 09:48:35 2017] netlink_sendmsg+0x29c/0x378
[Wed Oct 11 09:48:35 2017] sock_sendmsg+0x1c/0x2c
[Wed Oct 11 09:48:35 2017] ___sys_sendmsg+0x214/0x22c
[Wed Oct 11 09:48:35 2017] __sys_sendmsg+0x48/0x74
[Wed Oct 11 09:48:35 2017] SyS_sendmsg+0x10/0x14
[Wed Oct 11 09:48:35 2017] ret_fast_syscall+0x0/0x1c
[Wed Oct 11 09:48:35 2017] }
[Wed Oct 11 09:48:35 2017] ... key at: [<bf1535b8>]
__key.33453+0x0/0xffffba48 [wireguard]
[Wed Oct 11 09:48:35 2017] ... acquired at:
[Wed Oct 11 09:48:35 2017] iptunnel_xmit+0x174/0x1e0
[Wed Oct 11 09:48:35 2017] udp_tunnel_xmit_skb+0xe8/0xf0
[Wed Oct 11 09:48:35 2017] socket_send_skb_to_peer+0x400/0x830 [wireguard]
[Wed Oct 11 09:48:35 2017] packet_tx_worker+0xc8/0x3e4 [wireguard]
[Wed Oct 11 09:48:35 2017] process_one_work+0x24c/0x4e8
[Wed Oct 11 09:48:35 2017] worker_thread+0x40/0x574
[Wed Oct 11 09:48:35 2017] kthread+0x120/0x160
[Wed Oct 11 09:48:35 2017] ret_from_fork+0x14/0x24
[Wed Oct 11 09:48:35 2017] -> (&(&r->consumer_lock)->rlock){+.-...}
ops: 134865 {
[Wed Oct 11 09:48:35 2017] HARDIRQ-ON-W at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017] _raw_spin_lock_bh+0x4c/0x5c
[Wed Oct 11 09:48:35 2017]
packet_encrypt_worker+0x2c/0x574 [wireguard]
[Wed Oct 11 09:48:35 2017] process_one_work+0x24c/0x4e8
[Wed Oct 11 09:48:35 2017] worker_thread+0x40/0x574
[Wed Oct 11 09:48:35 2017] kthread+0x120/0x160
[Wed Oct 11 09:48:35 2017] ret_from_fork+0x14/0x24
[Wed Oct 11 09:48:35 2017] IN-SOFTIRQ-W at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017] _raw_spin_lock_bh+0x4c/0x5c
[Wed Oct 11 09:48:35 2017]
packet_queue_free+0x24/0x84 [wireguard]
[Wed Oct 11 09:48:35 2017] rcu_release+0x48/0x6c
[wireguard]
[Wed Oct 11 09:48:35 2017]
rcu_process_callbacks+0x338/0x5d0
[Wed Oct 11 09:48:35 2017] __do_softirq+0xf0/0x2a0
[Wed Oct 11 09:48:35 2017] irq_exit+0xe8/0x160
[Wed Oct 11 09:48:35 2017] __handle_domain_irq+0x60/0xc0
[Wed Oct 11 09:48:35 2017] gic_handle_irq+0x64/0xc4
[Wed Oct 11 09:48:35 2017] __irq_svc+0x70/0x98
[Wed Oct 11 09:48:35 2017] cpuidle_enter_state+0x188/0x2b0
[Wed Oct 11 09:48:35 2017] cpuidle_enter+0x1c/0x20
[Wed Oct 11 09:48:35 2017] call_cpuidle+0x28/0x44
[Wed Oct 11 09:48:35 2017] do_idle+0x10c/0x1e0
[Wed Oct 11 09:48:35 2017] cpu_startup_entry+0x20/0x24
[Wed Oct 11 09:48:35 2017]
secondary_start_kernel+0x148/0x174
[Wed Oct 11 09:48:35 2017] 0x801015ec
[Wed Oct 11 09:48:35 2017] INITIAL USE at:
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017] _raw_spin_lock_bh+0x4c/0x5c
[Wed Oct 11 09:48:35 2017]
packet_encrypt_worker+0x2c/0x574 [wireguard]
[Wed Oct 11 09:48:35 2017] process_one_work+0x24c/0x4e8
[Wed Oct 11 09:48:35 2017] worker_thread+0x40/0x574
[Wed Oct 11 09:48:35 2017] kthread+0x120/0x160
[Wed Oct 11 09:48:35 2017] ret_from_fork+0x14/0x24
[Wed Oct 11 09:48:35 2017] }
[Wed Oct 11 09:48:35 2017] ... key at: [<bf153640>]
__key.48712+0x0/0xffffb9c0 [wireguard]
[Wed Oct 11 09:48:35 2017] ... acquired at:
[Wed Oct 11 09:48:35 2017] mark_lock+0x2f8/0x6f0
[Wed Oct 11 09:48:35 2017] __lock_acquire+0x590/0x18e0
[Wed Oct 11 09:48:35 2017] lock_acquire+0x70/0x90
[Wed Oct 11 09:48:35 2017] _raw_spin_lock_bh+0x4c/0x5c
[Wed Oct 11 09:48:35 2017] packet_queue_free+0x24/0x84 [wireguard]
[Wed Oct 11 09:48:35 2017] rcu_release+0x48/0x6c [wireguard]
[Wed Oct 11 09:48:35 2017] rcu_process_callbacks+0x338/0x5d0
[Wed Oct 11 09:48:35 2017] __do_softirq+0xf0/0x2a0
[Wed Oct 11 09:48:35 2017] irq_exit+0xe8/0x160
[Wed Oct 11 09:48:35 2017] __handle_domain_irq+0x60/0xc0
[Wed Oct 11 09:48:35 2017] gic_handle_irq+0x64/0xc4
[Wed Oct 11 09:48:35 2017] __irq_svc+0x70/0x98
[Wed Oct 11 09:48:35 2017] cpuidle_enter_state+0x188/0x2b0
[Wed Oct 11 09:48:35 2017] cpuidle_enter+0x1c/0x20
[Wed Oct 11 09:48:35 2017] call_cpuidle+0x28/0x44
[Wed Oct 11 09:48:35 2017] do_idle+0x10c/0x1e0
[Wed Oct 11 09:48:35 2017] cpu_startup_entry+0x20/0x24
[Wed Oct 11 09:48:35 2017] secondary_start_kernel+0x148/0x174
[Wed Oct 11 09:48:35 2017] 0x801015ec
[Wed Oct 11 09:48:35 2017]
stack backtrace:
[Wed Oct 11 09:48:35 2017] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G
O 4.13.5-dirty #16
[Wed Oct 11 09:48:35 2017] Hardware name: Freescale i.MX6
Quad/DualLite (Device Tree)
[Wed Oct 11 09:48:35 2017] Backtrace:
[Wed Oct 11 09:48:35 2017] [<c010c3b8>] (dump_backtrace) from
[<c010c664>] (show_stack+0x18/0x1c)
[Wed Oct 11 09:48:35 2017] r7:00000000 r6:60010193 r5:00000000 r4:c0e69be0
[Wed Oct 11 09:48:35 2017] [<c010c64c>] (show_stack) from [<c090c8d8>]
(dump_stack+0xb4/0xe8)
[Wed Oct 11 09:48:35 2017] [<c090c824>] (dump_stack) from [<c016c874>]
(print_irq_inversion_bug+0x1a0/0x214)
[Wed Oct 11 09:48:35 2017] r9:00000004 r8:00000000 r7:c0ea3464
r6:cb879980 r5:c0ea3464 r4:cb885c34
[Wed Oct 11 09:48:35 2017] [<c016c6d4>] (print_irq_inversion_bug) from
[<c016c998>] (check_usage_forwards+0xb0/0x120)
[Wed Oct 11 09:48:35 2017] r9:00000004 r8:00000001 r7:c0bbc72c
r6:cb879980 r5:00000006 r4:cb879ea0
[Wed Oct 11 09:48:35 2017] [<c016c8e8>] (check_usage_forwards) from
[<c016d86c>] (mark_lock+0x2f8/0x6f0)
[Wed Oct 11 09:48:35 2017] r8:c0a028e8 r7:c016c8e8 r6:cb879980
r5:00000004 r4:cb879ea0
[Wed Oct 11 09:48:35 2017] [<c016d574>] (mark_lock) from [<c016e7d8>]
(__lock_acquire+0x590/0x18e0)
[Wed Oct 11 09:48:35 2017] r10:cb879980 r9:c0e1de7c r8:00000024
r7:c163a298 r6:00000001 r5:cb879ea0
[Wed Oct 11 09:48:35 2017] r4:0000042e
[Wed Oct 11 09:48:35 2017] [<c016e248>] (__lock_acquire) from
[<c01702d8>] (lock_acquire+0x70/0x90)
[Wed Oct 11 09:48:35 2017] r10:0000000a r9:c0e1325c r8:00000001
r7:00000001 r6:60010113 r5:00000000
[Wed Oct 11 09:48:35 2017] r4:ffffe000
[Wed Oct 11 09:48:35 2017] [<c0170268>] (lock_acquire) from
[<c09280bc>] (_raw_spin_lock_bh+0x4c/0x5c)
[Wed Oct 11 09:48:35 2017] r8:bf133cc8 r7:cb885e00 r6:cbdab920
r5:bf1350ac r4:cb3a2188
[Wed Oct 11 09:48:35 2017] [<c0928070>] (_raw_spin_lock_bh) from
[<bf1350ac>] (packet_queue_free+0x24/0x84 [wireguard])
[Wed Oct 11 09:48:35 2017] r5:cb3a2188 r4:cb3a2140
[Wed Oct 11 09:48:35 2017] [<bf135088>] (packet_queue_free
[wireguard]) from [<bf133d10>] (rcu_release+0x48/0x6c [wireguard])
[Wed Oct 11 09:48:35 2017] r5:cb3a2008 r4:cb3a2638
[Wed Oct 11 09:48:35 2017] [<bf133cc8>] (rcu_release [wireguard]) from
[<c0188ecc>] (rcu_process_callbacks+0x338/0x5d0)
[Wed Oct 11 09:48:35 2017] r5:cb3a2638 r4:cbdab900
[Wed Oct 11 09:48:35 2017] [<c0188b94>] (rcu_process_callbacks) from
[<c012a080>] (__do_softirq+0xf0/0x2a0)
[Wed Oct 11 09:48:35 2017] r10:00000100 r9:c0e020a0 r8:c0e020a4
r7:00000009 r6:cb884000 r5:40000001
[Wed Oct 11 09:48:35 2017] r4:00000000
[Wed Oct 11 09:48:35 2017] [<c0129f90>] (__do_softirq) from
[<c012a5dc>] (irq_exit+0xe8/0x160)
[Wed Oct 11 09:48:35 2017] r10:f4000100 r9:c0e1e0e4 r8:cb808400
r7:00000001 r6:00000000 r5:00000000
[Wed Oct 11 09:48:35 2017] r4:c0d53c18
[Wed Oct 11 09:48:35 2017] [<c012a4f4>] (irq_exit) from [<c0179694>]
(__handle_domain_irq+0x60/0xc0)
[Wed Oct 11 09:48:35 2017] [<c0179634>] (__handle_domain_irq) from
[<c01014fc>] (gic_handle_irq+0x64/0xc4)
[Wed Oct 11 09:48:35 2017] r9:c0e1e0e4 r8:cb885f00 r7:00000000
r6:000003ff r5:000003eb r4:f400010c
[Wed Oct 11 09:48:35 2017] [<c0101498>] (gic_handle_irq) from
[<c010d230>] (__irq_svc+0x70/0x98)
[Wed Oct 11 09:48:36 2017] Exception stack(0xcb885f00 to 0xcb885f48)
[Wed Oct 11 09:48:36 2017] 5f00: 00000001 00000001 00000000 cb879980
00000000 cbdaa4e0 173a2208 000026ee
[Wed Oct 11 09:48:36 2017] 5f20: 16a377b8 000026ee 00000000 cb885f7c
cb885f20 cb885f50 c016de00 c064d0c8
[Wed Oct 11 09:48:36 2017] 5f40: 20010013 ffffffff
[Wed Oct 11 09:48:36 2017] r10:00000000 r9:cb884000 r8:16a377b8
r7:cb885f34 r6:ffffffff r5:20010013
[Wed Oct 11 09:48:36 2017] r4:c064d0c8
[Wed Oct 11 09:48:36 2017] [<c064cf40>] (cpuidle_enter_state) from
[<c064d230>] (cpuidle_enter+0x1c/0x20)
[Wed Oct 11 09:48:36 2017] r10:cb885fa0 r9:c0e0d1fc r8:c0d534d8
r7:cbdaa4e0 r6:c0e0756c r5:c0e075b8
[Wed Oct 11 09:48:36 2017] r4:cb884000 r3:cbdaa4e0
[Wed Oct 11 09:48:36 2017] [<c064d214>] (cpuidle_enter) from
[<c0165ce8>] (call_cpuidle+0x28/0x44)
[Wed Oct 11 09:48:36 2017] [<c0165cc0>] (call_cpuidle) from
[<c0165f08>] (do_idle+0x10c/0x1e0)
[Wed Oct 11 09:48:36 2017] [<c0165dfc>] (do_idle) from [<c0166364>]
(cpu_startup_entry+0x20/0x24)
[Wed Oct 11 09:48:36 2017] r10:00000000 r9:412fc09a r8:8000406a
r7:c0e6d2d0 r6:10c0387d r5:00000003
[Wed Oct 11 09:48:36 2017] r4:00000084 r3:cb879980
[Wed Oct 11 09:48:36 2017] [<c0166344>] (cpu_startup_entry) from
[<c010f4e8>] (secondary_start_kernel+0x148/0x174)
[Wed Oct 11 09:48:36 2017] [<c010f3a0>] (secondary_start_kernel) from
[<801015ec>] (0x801015ec)
[Wed Oct 11 09:48:36 2017] r5:00000051 r4:8b86c06a
[Wed Oct 11 09:48:36 2017] wireguard: wg0: Interface deleted
DMESG second:
[ 72.876333] ========================================================
[ 72.882714] WARNING: possible irq lock inversion dependency detected
[ 72.889097] 4.13.5-dirty #16 Tainted: G O
[ 72.894256] --------------------------------------------------------
[ 72.900634] swapper/2/0 just changed the state of lock:
[ 72.905878] (&(&r->consumer_lock)->rlock){+.-...}, at:
[<bf0400ac>] packet_queue_free+0x24/0x84 [wireguard]
[ 72.915824] but this lock took another, SOFTIRQ-unsafe lock in the past:
[ 72.922549] (&syncp->seq#7){+.+...}
[ 72.922570]
and interrupts could create inverse lock ordering
between them.
[ 72.937601]
other info that might help us debug this:
[ 72.944166] Possible interrupt unsafe locking scenario:
[ 72.950990] CPU0 CPU1
[ 72.955544] ---- ----
[ 72.960097] lock(&syncp->seq#7);
[ 72.963531] local_irq_disable();
[ 72.969477]
lock(&(&r->consumer_lock)->rlock);
[ 72.976647] lock(&syncp->seq#7);
[ 72.982604] <Interrupt>
[ 72.985242] lock(&(&r->consumer_lock)->rlock);
[ 72.990064]
*** DEADLOCK ***
[ 72.996029] 1 lock held by swapper/2/0:
[ 72.999886] #0: (rcu_callback){......}, at: [<c0188e90>]
rcu_process_callbacks+0x2fc/0x5d0
[ 73.008394]
the shortest dependencies between 2nd lock and 1st lock:
[ 73.016265] -> (&syncp->seq#7){+.+...} ops: 218091 {
[ 73.021368] HARDIRQ-ON-W at:
[ 73.024637] lock_acquire+0x70/0x90
[ 73.029988] iptunnel_xmit+0x174/0x1e0
[ 73.035597] udp_tunnel_xmit_skb+0xe8/0xf0
[ 73.041588]
socket_send_skb_to_peer+0x400/0x830 [wireguard]
[ 73.049147]
socket_send_buffer_to_peer+0x74/0x84 [wireguard]
[ 73.056789]
packet_send_handshake_initiation+0xb8/0xf8 [wireguard]
[ 73.064949]
packet_handshake_send_worker+0x18/0x24 [wireguard]
[ 73.072740] process_one_work+0x24c/0x4e8
[ 73.078607] worker_thread+0x40/0x574
[ 73.084124] kthread+0x120/0x160
[ 73.089211] ret_from_fork+0x14/0x24
[ 73.094638] SOFTIRQ-ON-W at:
[ 73.097901] lock_acquire+0x70/0x90
[ 73.103278]
receive_handshake_packet+0x114/0x3f0 [wireguard]
[ 73.110920]
packet_handshake_receive_worker+0x1c/0x44 [wireguard]
[ 73.118973] process_one_work+0x24c/0x4e8
[ 73.124838] worker_thread+0x40/0x574
[ 73.130351] kthread+0x120/0x160
[ 73.135436] ret_from_fork+0x14/0x24
[ 73.140862] INITIAL USE at:
[ 73.144037] lock_acquire+0x70/0x90
[ 73.149296] ip_tunnel_get_stats64+0x148/0x190
[ 73.155513] dev_get_stats+0x40/0xb4
[ 73.160862] rtnl_fill_stats+0x38/0x120
[ 73.166468] rtnl_fill_ifinfo+0x508/0xe00
[ 73.172248] rtmsg_ifinfo_build_skb+0x70/0xe0
[ 73.178376] rtmsg_ifinfo_event.part.7+0x1c/0x4c
[ 73.184764] rtmsg_ifinfo+0x30/0x38
[ 73.190022] __dev_notify_flags+0x94/0xa4
[ 73.195800] rtnl_configure_link+0x80/0xa4
[ 73.201662] rtnl_newlink+0x64c/0x748
[ 73.207091] rtnetlink_rcv_msg+0x94/0x1f4
[ 73.212871] netlink_rcv_skb+0xe0/0x100
[ 73.218475] rtnetlink_rcv+0x28/0x38
[ 73.223816] netlink_unicast+0x184/0x26c
[ 73.229505] netlink_sendmsg+0x29c/0x378
[ 73.235200] sock_sendmsg+0x1c/0x2c
[ 73.240454] ___sys_sendmsg+0x214/0x22c
[ 73.246057] __sys_sendmsg+0x48/0x74
[ 73.251399] SyS_sendmsg+0x10/0x14
[ 73.256568] ret_fast_syscall+0x0/0x1c
[ 73.262080] }
[ 73.263896] ... key at: [<bf05e5b8>]
__key.33453+0x0/0xffffba48 [wireguard]
[ 73.271509] ... acquired at:
[ 73.274590] iptunnel_xmit+0x174/0x1e0
[ 73.278541] udp_tunnel_xmit_skb+0xe8/0xf0
[ 73.282870] socket_send_skb_to_peer+0x400/0x830 [wireguard]
[ 73.288764] packet_tx_worker+0xc8/0x3e4 [wireguard]
[ 73.293935] process_one_work+0x24c/0x4e8
[ 73.298146] worker_thread+0x40/0x574
[ 73.302006] kthread+0x120/0x160
[ 73.305435] ret_from_fork+0x14/0x24
[ 73.310714] -> (&(&r->consumer_lock)->rlock){+.-...} ops: 82639 {
[ 73.316857] HARDIRQ-ON-W at:
[ 73.320032] lock_acquire+0x70/0x90
[ 73.325209] _raw_spin_lock_bh+0x4c/0x5c
[ 73.330848] packet_encrypt_worker+0x2c/0x574
[wireguard]
[ 73.337934] process_one_work+0x24c/0x4e8
[ 73.343624] worker_thread+0x40/0x574
[ 73.348965] kthread+0x120/0x160
[ 73.353874] ret_from_fork+0x14/0x24
[ 73.359126] IN-SOFTIRQ-W at:
[ 73.362298] lock_acquire+0x70/0x90
[ 73.367469] _raw_spin_lock_bh+0x4c/0x5c
[ 73.373107] packet_queue_free+0x24/0x84 [wireguard]
[ 73.379786] rcu_release+0x48/0x6c [wireguard]
[ 73.385915] rcu_process_callbacks+0x338/0x5d0
[ 73.392049] __do_softirq+0xf0/0x2a0
[ 73.397302] irq_exit+0xe8/0x160
[ 73.402215] __handle_domain_irq+0x60/0xc0
[ 73.407994] gic_handle_irq+0x64/0xc4
[ 73.413336] __irq_svc+0x70/0x98
[ 73.418247] cpuidle_enter_state+0x188/0x2b0
[ 73.424195] cpuidle_enter+0x1c/0x20
[ 73.429450] call_cpuidle+0x28/0x44
[ 73.434616] do_idle+0x10c/0x1e0
[ 73.439520] cpu_startup_entry+0x20/0x24
[ 73.445124] secondary_start_kernel+0x148/0x174
[ 73.451337] 0x801015ec
[ 73.455457] INITIAL USE at:
[ 73.458543] lock_acquire+0x70/0x90
[ 73.463627] _raw_spin_lock_bh+0x4c/0x5c
[ 73.469183] packet_encrypt_worker+0x2c/0x574 [wireguard]
[ 73.476182] process_one_work+0x24c/0x4e8
[ 73.481785] worker_thread+0x40/0x574
[ 73.487039] kthread+0x120/0x160
[ 73.491861] ret_from_fork+0x14/0x24
[ 73.497024] }
[ 73.498745] ... key at: [<bf05e640>]
__key.48712+0x0/0xffffb9c0 [wireguard]
[ 73.506268] ... acquired at:
[ 73.509263] mark_lock+0x2f8/0x6f0
[ 73.512865] __lock_acquire+0x590/0x18e0
[ 73.516989] lock_acquire+0x70/0x90
[ 73.520678] _raw_spin_lock_bh+0x4c/0x5c
[ 73.524832] packet_queue_free+0x24/0x84 [wireguard]
[ 73.530029] rcu_release+0x48/0x6c [wireguard]
[ 73.534676] rcu_process_callbacks+0x338/0x5d0
[ 73.539325] __do_softirq+0xf0/0x2a0
[ 73.543099] irq_exit+0xe8/0x160
[ 73.546529] __handle_domain_irq+0x60/0xc0
[ 73.550826] gic_handle_irq+0x64/0xc4
[ 73.554687] __irq_svc+0x70/0x98
[ 73.558113] cpuidle_enter_state+0x188/0x2b0
[ 73.562583] cpuidle_enter+0x1c/0x20
[ 73.566358] call_cpuidle+0x28/0x44
[ 73.570044] do_idle+0x10c/0x1e0
[ 73.573470] cpu_startup_entry+0x20/0x24
[ 73.577592] secondary_start_kernel+0x148/0x174
[ 73.582324] 0x801015ec
[ 73.586471]
stack backtrace:
[ 73.590865] CPU: 2 PID: 0 Comm: swapper/2 Tainted: G O
4.13.5-dirty #16
[ 73.598647] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
[ 73.605207] Backtrace:
[ 73.607692] [<c010c3b8>] (dump_backtrace) from [<c010c664>]
(show_stack+0x18/0x1c)
[ 73.615307] r7:00000000 r6:60070193 r5:00000000 r4:c0e69be0
[ 73.621007] [<c010c64c>] (show_stack) from [<c090c8d8>]
(dump_stack+0xb4/0xe8)
[ 73.628281] [<c090c824>] (dump_stack) from [<c016c874>]
(print_irq_inversion_bug+0x1a0/0x214)
[ 73.636852] r9:00000004 r8:00000000 r7:c0e9c42c r6:cb878cc0
r5:c0e9c42c r4:cb883c34
[ 73.644642] [<c016c6d4>] (print_irq_inversion_bug) from
[<c016c998>] (check_usage_forwards+0xb0/0x120)
[ 73.653996] r9:00000004 r8:00000001 r7:c0bbc72c r6:cb878cc0
r5:00000006 r4:cb8791e0
[ 73.661785] [<c016c8e8>] (check_usage_forwards) from [<c016d86c>]
(mark_lock+0x2f8/0x6f0)
[ 73.670005] r8:c0a028e8 r7:c016c8e8 r6:cb878cc0 r5:00000004 r4:cb8791e0
[ 73.676743] [<c016d574>] (mark_lock) from [<c016e7d8>]
(__lock_acquire+0x590/0x18e0)
[ 73.684528] r10:cb878cc0 r9:c0e1de7c r8:00000024 r7:c163a298
r6:00000001 r5:cb8791e0
[ 73.692398] r4:0000040c
[ 73.694959] [<c016e248>] (__lock_acquire) from [<c01702d8>]
(lock_acquire+0x70/0x90)
[ 73.702746] r10:0000000a r9:c0e1325c r8:00000001 r7:00000001
r6:60070113 r5:00000000
[ 73.710614] r4:ffffe000
[ 73.713178] [<c0170268>] (lock_acquire) from [<c09280bc>]
(_raw_spin_lock_bh+0x4c/0x5c)
[ 73.721225] r8:bf03ecc8 r7:cb883e00 r6:cbd9b920 r5:bf0400ac r4:cb3da188
[ 73.728004] [<c0928070>] (_raw_spin_lock_bh) from [<bf0400ac>]
(packet_queue_free+0x24/0x84 [wireguard])
[ 73.737534] r5:cb3da188 r4:cb3da140
[ 73.741196] [<bf040088>] (packet_queue_free [wireguard]) from
[<bf03ed10>] (rcu_release+0x48/0x6c [wireguard])
[ 73.751244] r5:cb3da008 r4:cb3da638
[ 73.754878] [<bf03ecc8>] (rcu_release [wireguard]) from
[<c0188ecc>] (rcu_process_callbacks+0x338/0x5d0)
[ 73.764404] r5:cb3da638 r4:cbd9b900
[ 73.768016] [<c0188b94>] (rcu_process_callbacks) from [<c012a080>]
(__do_softirq+0xf0/0x2a0)
[ 73.776503] r10:00000100 r9:c0e020a0 r8:c0e020a4 r7:00000009
r6:cb882000 r5:40000001
[ 73.784371] r4:00000000
[ 73.786931] [<c0129f90>] (__do_softirq) from [<c012a5dc>]
(irq_exit+0xe8/0x160)
[ 73.794283] r10:f4000100 r9:c0e1e0e4 r8:cb808400 r7:00000001
r6:00000000 r5:00000000
[ 73.802150] r4:c0d53c18
[ 73.804713] [<c012a4f4>] (irq_exit) from [<c0179694>]
(__handle_domain_irq+0x60/0xc0)
[ 73.812589] [<c0179634>] (__handle_domain_irq) from [<c01014fc>]
(gic_handle_irq+0x64/0xc4)
[ 73.820986] r9:c0e1e0e4 r8:cb883f00 r7:00000000 r6:000003ff
r5:000003eb r4:f400010c
[ 73.828773] [<c0101498>] (gic_handle_irq) from [<c010d230>]
(__irq_svc+0x70/0x98)
[ 73.836296] Exception stack(0xcb883f00 to 0xcb883f48)
[ 73.841380] 3f00: 00000001 00000001 00000000 cb878cc0 00000000
cbd9a4e0 f7ab2062 00000010
[ 73.849603] 3f20: f7154280 00000010 00000000 cb883f7c cb883f20
cb883f50 c016de00 c064d0c8
[ 73.857820] 3f40: 20070013 ffffffff
[ 73.861337] r10:00000000 r9:cb882000 r8:f7154280 r7:cb883f34
r6:ffffffff r5:20070013
[ 73.869206] r4:c064d0c8
[ 73.871766] [<c064cf40>] (cpuidle_enter_state) from [<c064d230>]
(cpuidle_enter+0x1c/0x20)
[ 73.880074] r10:cb883fa0 r9:c0e0d1fc r8:c0d534d8 r7:cbd9a4e0
r6:c0e0756c r5:c0e075b8
[ 73.887943] r4:cb882000 r3:cbd9a4e0
[ 73.891550] [<c064d214>] (cpuidle_enter) from [<c0165ce8>]
(call_cpuidle+0x28/0x44)
[ 73.899250] [<c0165cc0>] (call_cpuidle) from [<c0165f08>]
(do_idle+0x10c/0x1e0)
[ 73.906602] [<c0165dfc>] (do_idle) from [<c0166364>]
(cpu_startup_entry+0x20/0x24)
[ 73.914216] r10:00000000 r9:412fc09a r8:8000406a r7:c0e6d2d0
r6:10c0387d r5:00000002
[ 73.922085] r4:00000084 r3:cb878cc0
[ 73.925691] [<c0166344>] (cpu_startup_entry) from [<c010f4e8>]
(secondary_start_kernel+0x148/0x174)
[ 73.934785] [<c010f3a0>] (secondary_start_kernel) from [<801015ec>]
(0x801015ec)
[ 73.942219] r5:00000051 r4:8b86c06a
[ 74.025137] wireguard: wg0: Interface deleted
root@utilite:~#
DMESG third:
[ 83.786457] ========================================================
[ 83.792863] WARNING: possible irq lock inversion dependency detected
[ 83.799272] 4.13.5-dirty #16 Tainted: G O
[ 83.804455] --------------------------------------------------------
[ 83.810862] swapper/0/0 just changed the state of lock:
[ 83.816130] (&(&r->consumer_lock)->rlock){+.-...}, at:
[<bf0400ac>] packet_queue_free+0x24/0x84 [wireguard]
[ 83.826179] but this lock took another, SOFTIRQ-unsafe lock in the past:
[ 83.832930] (&syncp->seq#7){+.+...}
[ 83.832966]
and interrupts could create inverse lock ordering
between them.
[ 83.848067]
other info that might help us debug this:
[ 83.854674] Possible interrupt unsafe locking scenario:
[ 83.861540] CPU0 CPU1
[ 83.866118] ---- ----
[ 83.870672] lock(&syncp->seq#7);
[ 83.874107] local_irq_disable();
[ 83.880054]
lock(&(&r->consumer_lock)->rlock);
[ 83.887227] lock(&syncp->seq#7);
[ 83.893185] <Interrupt>
[ 83.895823] lock(&(&r->consumer_lock)->rlock);
[ 83.900645]
*** DEADLOCK ***
[ 83.906610] 1 lock held by swapper/0/0:
[ 83.910467] #0: (rcu_callback){......}, at: [<c0188e90>]
rcu_process_callbacks+0x2fc/0x5d0
[ 83.918980]
the shortest dependencies between 2nd lock and 1st lock:
[ 83.926852] -> (&syncp->seq#7){+.+...} ops: 221546 {
[ 83.931957] HARDIRQ-ON-W at:
[ 83.935225] lock_acquire+0x70/0x90
[ 83.940577] iptunnel_xmit+0x174/0x1e0
[ 83.946183] udp_tunnel_xmit_skb+0xe8/0xf0
[ 83.952178]
socket_send_skb_to_peer+0x400/0x830 [wireguard]
[ 83.959739]
socket_send_buffer_to_peer+0x74/0x84 [wireguard]
[ 83.967384]
packet_send_handshake_initiation+0xb8/0xf8 [wireguard]
[ 83.975544]
packet_handshake_send_worker+0x18/0x24 [wireguard]
[ 83.983337] process_one_work+0x24c/0x4e8
[ 83.989202] worker_thread+0x40/0x574
[ 83.994717] kthread+0x120/0x160
[ 83.999802] ret_from_fork+0x14/0x24
[ 84.005229] SOFTIRQ-ON-W at:
[ 84.008492] lock_acquire+0x70/0x90
[ 84.013869]
receive_handshake_packet+0x114/0x3f0 [wireguard]
[ 84.021512]
packet_handshake_receive_worker+0x1c/0x44 [wireguard]
[ 84.029561] process_one_work+0x24c/0x4e8
[ 84.035426] worker_thread+0x40/0x574
[ 84.040943] kthread+0x120/0x160
[ 84.046026] ret_from_fork+0x14/0x24
[ 84.051452] INITIAL USE at:
[ 84.054625] lock_acquire+0x70/0x90
[ 84.059882] ip_tunnel_get_stats64+0x148/0x190
[ 84.066097] dev_get_stats+0x40/0xb4
[ 84.071447] rtnl_fill_stats+0x38/0x120
[ 84.077050] rtnl_fill_ifinfo+0x508/0xe00
[ 84.082830] rtmsg_ifinfo_build_skb+0x70/0xe0
[ 84.088957] rtmsg_ifinfo_event.part.7+0x1c/0x4c
[ 84.095344] rtmsg_ifinfo+0x30/0x38
[ 84.100603] __dev_notify_flags+0x94/0xa4
[ 84.106383] rtnl_configure_link+0x80/0xa4
[ 84.112247] rtnl_newlink+0x64c/0x748
[ 84.117675] rtnetlink_rcv_msg+0x94/0x1f4
[ 84.123456] netlink_rcv_skb+0xe0/0x100
[ 84.129059] rtnetlink_rcv+0x28/0x38
[ 84.134401] netlink_unicast+0x184/0x26c
[ 84.140090] netlink_sendmsg+0x29c/0x378
[ 84.145785] sock_sendmsg+0x1c/0x2c
[ 84.151041] ___sys_sendmsg+0x214/0x22c
[ 84.156644] __sys_sendmsg+0x48/0x74
[ 84.161986] SyS_sendmsg+0x10/0x14
[ 84.167156] ret_fast_syscall+0x0/0x1c
[ 84.172668] }
[ 84.174484] ... key at: [<bf05e5b8>]
__key.33453+0x0/0xffffba48 [wireguard]
[ 84.182096] ... acquired at:
[ 84.185176] iptunnel_xmit+0x174/0x1e0
[ 84.189127] udp_tunnel_xmit_skb+0xe8/0xf0
[ 84.193457] socket_send_skb_to_peer+0x400/0x830 [wireguard]
[ 84.199351] packet_tx_worker+0xc8/0x3e4 [wireguard]
[ 84.204521] process_one_work+0x24c/0x4e8
[ 84.208731] worker_thread+0x40/0x574
[ 84.212591] kthread+0x120/0x160
[ 84.216020] ret_from_fork+0x14/0x24
[ 84.221300] -> (&(&r->consumer_lock)->rlock){+.-...} ops: 71666 {
[ 84.227443] HARDIRQ-ON-W at:
[ 84.230620] lock_acquire+0x70/0x90
[ 84.235797] _raw_spin_lock_bh+0x4c/0x5c
[ 84.241438] packet_encrypt_worker+0x2c/0x574
[wireguard]
[ 84.248524] process_one_work+0x24c/0x4e8
[ 84.254214] worker_thread+0x40/0x574
[ 84.259554] kthread+0x120/0x160
[ 84.264464] ret_from_fork+0x14/0x24
[ 84.269716] IN-SOFTIRQ-W at:
[ 84.272888] lock_acquire+0x70/0x90
[ 84.278060] _raw_spin_lock_bh+0x4c/0x5c
[ 84.283695] packet_queue_free+0x24/0x84 [wireguard]
[ 84.290371] rcu_release+0x48/0x6c [wireguard]
[ 84.296500] rcu_process_callbacks+0x338/0x5d0
[ 84.302634] __do_softirq+0xf0/0x2a0
[ 84.307889] irq_exit+0xe8/0x160
[ 84.312802] __handle_domain_irq+0x60/0xc0
[ 84.318582] gic_handle_irq+0x64/0xc4
[ 84.323925] __irq_svc+0x70/0x98
[ 84.328835] cpuidle_enter_state+0x188/0x2b0
[ 84.334785] cpuidle_enter+0x1c/0x20
[ 84.340040] call_cpuidle+0x28/0x44
[ 84.345206] do_idle+0x10c/0x1e0
[ 84.350112] cpu_startup_entry+0x20/0x24
[ 84.355714] rest_init+0x228/0x278
[ 84.360800] start_kernel+0x32c/0x3a0
[ 84.366141] 0x8000807c
[ 84.370261] INITIAL USE at:
[ 84.373348] lock_acquire+0x70/0x90
[ 84.378430] _raw_spin_lock_bh+0x4c/0x5c
[ 84.383984] packet_encrypt_worker+0x2c/0x574 [wireguard]
[ 84.390985] process_one_work+0x24c/0x4e8
[ 84.396589] worker_thread+0x40/0x574
[ 84.401843] kthread+0x120/0x160
[ 84.406666] ret_from_fork+0x14/0x24
[ 84.411829] }
[ 84.413550] ... key at: [<bf05e640>]
__key.48712+0x0/0xffffb9c0 [wireguard]
[ 84.421071] ... acquired at:
[ 84.424067] mark_lock+0x2f8/0x6f0
[ 84.427669] __lock_acquire+0x590/0x18e0
[ 84.431793] lock_acquire+0x70/0x90
[ 84.435482] _raw_spin_lock_bh+0x4c/0x5c
[ 84.439637] packet_queue_free+0x24/0x84 [wireguard]
[ 84.444836] rcu_release+0x48/0x6c [wireguard]
[ 84.449483] rcu_process_callbacks+0x338/0x5d0
[ 84.454132] __do_softirq+0xf0/0x2a0
[ 84.457908] irq_exit+0xe8/0x160
[ 84.461338] __handle_domain_irq+0x60/0xc0
[ 84.465634] gic_handle_irq+0x64/0xc4
[ 84.469494] __irq_svc+0x70/0x98
[ 84.472921] cpuidle_enter_state+0x188/0x2b0
[ 84.477390] cpuidle_enter+0x1c/0x20
[ 84.481165] call_cpuidle+0x28/0x44
[ 84.484852] do_idle+0x10c/0x1e0
[ 84.488278] cpu_startup_entry+0x20/0x24
[ 84.492401] rest_init+0x228/0x278
[ 84.496004] start_kernel+0x32c/0x3a0
[ 84.499864] 0x8000807c
[ 84.504013]
stack backtrace:
[ 84.508408] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G O
4.13.5-dirty #16
[ 84.516191] Hardware name: Freescale i.MX6 Quad/DualLite (Device Tree)
[ 84.522748] Backtrace:
[ 84.525234] [<c010c3b8>] (dump_backtrace) from [<c010c664>]
(show_stack+0x18/0x1c)
[ 84.532849] r7:00000000 r6:60080193 r5:00000000 r4:c0e69be0
[ 84.538549] [<c010c64c>] (show_stack) from [<c090c8d8>]
(dump_stack+0xb4/0xe8)
[ 84.545821] [<c090c824>] (dump_stack) from [<c016c874>]
(print_irq_inversion_bug+0x1a0/0x214)
[ 84.554393] r9:00000004 r8:00000000 r7:c0e9c2c4 r6:c0e0a840
r5:c0e9c2c4 r4:c0e01bdc
[ 84.562184] [<c016c6d4>] (print_irq_inversion_bug) from
[<c016c998>] (check_usage_forwards+0xb0/0x120)
[ 84.571538] r9:00000004 r8:00000001 r7:c0bbc72c r6:c0e0a840
r5:00000006 r4:c0e0ad60
[ 84.579328] [<c016c8e8>] (check_usage_forwards) from [<c016d86c>]
(mark_lock+0x2f8/0x6f0)
[ 84.587549] r8:c0a028e8 r7:c016c8e8 r6:c0e0a840 r5:00000004 r4:c0e0ad60
[ 84.594287] [<c016d574>] (mark_lock) from [<c016e7d8>]
(__lock_acquire+0x590/0x18e0)
[ 84.602075] r10:c0e0a840 r9:c0e1de7c r8:00000024 r7:c163a298
r6:00000001 r5:c0e0ad60
[ 84.609943] r4:00000405
[ 84.612505] [<c016e248>] (__lock_acquire) from [<c01702d8>]
(lock_acquire+0x70/0x90)
[ 84.620291] r10:0000000a r9:c0e1325c r8:00000001 r7:00000001
r6:60080113 r5:00000000
[ 84.628160] r4:ffffe000
[ 84.630723] [<c0170268>] (lock_acquire) from [<c09280bc>]
(_raw_spin_lock_bh+0x4c/0x5c)
[ 84.638770] r8:bf03ecc8 r7:c0e01da8 r6:cbd7b920 r5:bf0400ac r4:ca564188
[ 84.645550] [<c0928070>] (_raw_spin_lock_bh) from [<bf0400ac>]
(packet_queue_free+0x24/0x84 [wireguard])
[ 84.655079] r5:ca564188 r4:ca564140
[ 84.658742] [<bf040088>] (packet_queue_free [wireguard]) from
[<bf03ed10>] (rcu_release+0x48/0x6c [wireguard])
[ 84.668790] r5:ca564008 r4:ca564638
[ 84.672422] [<bf03ecc8>] (rcu_release [wireguard]) from
[<c0188ecc>] (rcu_process_callbacks+0x338/0x5d0)
[ 84.681948] r5:ca564638 r4:cbd7b900
[ 84.685557] [<c0188b94>] (rcu_process_callbacks) from [<c012a080>]
(__do_softirq+0xf0/0x2a0)
[ 84.694042] r10:00000100 r9:c0e020a0 r8:c0e020a4 r7:00000009
r6:c0e00000 r5:40000001
[ 84.701911] r4:00000000
[ 84.704470] [<c0129f90>] (__do_softirq) from [<c012a5dc>]
(irq_exit+0xe8/0x160)
[ 84.711821] r10:f4000100 r9:c0e1e0e4 r8:cb808400 r7:00000001
r6:00000000 r5:00000000
[ 84.719690] r4:c0d53c18
[ 84.722253] [<c012a4f4>] (irq_exit) from [<c0179694>]
(__handle_domain_irq+0x60/0xc0)
[ 84.730129] [<c0179634>] (__handle_domain_irq) from [<c01014fc>]
(gic_handle_irq+0x64/0xc4)
[ 84.738526] r9:c0e1e0e4 r8:c0e01ea8 r7:00000000 r6:000003ff
r5:000003eb r4:f400010c
[ 84.746313] [<c0101498>] (gic_handle_irq) from [<c010d230>]
(__irq_svc+0x70/0x98)
[ 84.753837] Exception stack(0xc0e01ea8 to 0xc0e01ef0)
[ 84.758920] 1ea0: 00000001 00000001 00000000
c0e0a840 00000000 cbd7a4e0
[ 84.767142] 1ec0: 81f5899f 00000013 815e6b6d 00000013 00000000
c0e01f24 c0e01ec8 c0e01ef8
[ 84.775360] 1ee0: c016de00 c064d0c8 20080013 ffffffff
[ 84.780443] r10:00000000 r9:c0e00000 r8:815e6b6d r7:c0e01edc
r6:ffffffff r5:20080013
[ 84.788312] r4:c064d0c8
[ 84.790872] [<c064cf40>] (cpuidle_enter_state) from [<c064d230>]
(cpuidle_enter+0x1c/0x20)
[ 84.799182] r10:c0e01f48 r9:c0e0d1fc r8:c0d534d8 r7:cbd7a4e0
r6:c0e0756c r5:c0e075b8
[ 84.807051] r4:c0e00000 r3:cbd7a4e0
[ 84.810654] [<c064d214>] (cpuidle_enter) from [<c0165ce8>]
(call_cpuidle+0x28/0x44)
[ 84.818354] [<c0165cc0>] (call_cpuidle) from [<c0165f08>]
(do_idle+0x10c/0x1e0)
[ 84.825706] [<c0165dfc>] (do_idle) from [<c0166364>]
(cpu_startup_entry+0x20/0x24)
[ 84.833319] r10:c0d3da48 r9:cbfff980 r8:c0e6d000 r7:c0e07540
r6:c0e6d000 r5:00000002
[ 84.841187] r4:000000bb r3:c0d4c31c
[ 84.844791] [<c0166344>] (cpu_startup_entry) from [<c09205e4>]
(rest_init+0x228/0x278)
[ 84.852757] [<c09203bc>] (rest_init) from [<c0d00cd4>]
(start_kernel+0x32c/0x3a0)
[ 84.860280] r5:ffffffff r4:c0e6d04c
[ 84.863885] [<c0d009a8>] (start_kernel) from [<8000807c>] (0x8000807c)
[ 84.954784] wireguard: wg0: Interface deleted
Greats,
René
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: possible irq lock inversion dependency detected
2017-10-11 12:49 ` René van Dorst
@ 2017-10-11 12:51 ` Jason A. Donenfeld
2017-10-11 13:30 ` René van Dorst
0 siblings, 1 reply; 7+ messages in thread
From: Jason A. Donenfeld @ 2017-10-11 12:51 UTC (permalink / raw)
To: René van Dorst; +Cc: WireGuard mailing list
Hi Ren=C3=A9,
I'm having trouble parsing your message. You wrote:
> So I am not sure if you patch works or not.
> Because it was not that easy to reproduce the last one.
Do you mean to imply that you could NOT reproduce it with my patch?
But that you could reproduce it WITHOUT the patch?
Jason
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: possible irq lock inversion dependency detected
2017-10-11 12:51 ` Jason A. Donenfeld
@ 2017-10-11 13:30 ` René van Dorst
2017-10-11 13:46 ` Jason A. Donenfeld
0 siblings, 1 reply; 7+ messages in thread
From: René van Dorst @ 2017-10-11 13:30 UTC (permalink / raw)
To: Jason A. Donenfeld; +Cc: WireGuard mailing list
Quoting "Jason A. Donenfeld" <Jason@zx2c4.com>:
> Hi René,
>
> I'm having trouble parsing your message. You wrote:
>
>> So I am not sure if you patch works or not.
>> Because it was not that easy to reproduce the last one.
>
> Do you mean to imply that you could NOT reproduce it with my patch?
> But that you could reproduce it WITHOUT the patch?
>
> Jason
I was trying to reproduce the bug before the patch.
I could not reproduce the first one. Only hitting the second one 3 times.
After the patch I could not reproduce any of them.
Greats,
René
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: possible irq lock inversion dependency detected
2017-10-11 13:30 ` René van Dorst
@ 2017-10-11 13:46 ` Jason A. Donenfeld
0 siblings, 0 replies; 7+ messages in thread
From: Jason A. Donenfeld @ 2017-10-11 13:46 UTC (permalink / raw)
To: René van Dorst; +Cc: WireGuard mailing list
Hi Ren=C3=A9,
Great, I'll ship it! Thanks for debugging.
Jason
^ permalink raw reply [flat|nested] 7+ messages in thread
* possible irq lock inversion dependency detected
@ 2016-02-06 10:07 Михаил Гаврилов
0 siblings, 0 replies; 7+ messages in thread
From: Михаил Гаврилов @ 2016-02-06 10:07 UTC (permalink / raw)
To: linux-kernel
Hi! I see this message in my dmesg log.
I don't know how this information is useful for developer.
But I want helps to do Linux kernel better.
[ 1401.201555] =========================================================
[ 1401.201557] [ INFO: possible irq lock inversion dependency detected ]
[ 1401.201559] 4.3.5-300.fc23.x86_64+debug #1 Not tainted
[ 1401.201560] ---------------------------------------------------------
[ 1401.201562] kswapd0/80 just changed the state of lock:
[ 1401.201563] (&delayed_node->mutex){+.+.-.}, at:
[<ffffffffa084dccd>] __btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.201585] but this lock took another, RECLAIM_FS-unsafe lock in the past:
[ 1401.201586] (&fs_info->commit_root_sem){+++++.}
and interrupts could create inverse lock ordering between them.
[ 1401.201590]
other info that might help us debug this:
[ 1401.201591] Chain exists of:
&delayed_node->mutex --> &found->groups_sem -->
&fs_info->commit_root_sem
[ 1401.201596] Possible interrupt unsafe locking scenario:
[ 1401.201597] CPU0 CPU1
[ 1401.201598] ---- ----
[ 1401.201599] lock(&fs_info->commit_root_sem);
[ 1401.201601] local_irq_disable();
[ 1401.201602] lock(&delayed_node->mutex);
[ 1401.201604] lock(&found->groups_sem);
[ 1401.201606] <Interrupt>
[ 1401.201607] lock(&delayed_node->mutex);
[ 1401.201609]
*** DEADLOCK ***
[ 1401.201611] 2 locks held by kswapd0/80:
[ 1401.201612] #0: (shrinker_rwsem){++++..}, at:
[<ffffffff811f533b>] shrink_slab.part.41+0x5b/0x540
[ 1401.201620] #1: (&type->s_umount_key#57){.+.+..}, at:
[<ffffffff8127130b>] trylock_super+0x1b/0x50
[ 1401.201627]
the shortest dependencies between 2nd lock and 1st lock:
[ 1401.201636] -> (&fs_info->commit_root_sem){+++++.} ops: 1323 {
[ 1401.201640] HARDIRQ-ON-W at:
[ 1401.201642] [<ffffffff81107432>]
__lock_acquire+0x912/0x1ba0
[ 1401.201646] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201648] [<ffffffff818643da>]
down_write+0x5a/0xc0
[ 1401.201652] [<ffffffffa07dd386>]
btrfs_prepare_extent_commit+0x36/0x120 [btrfs]
[ 1401.201661] [<ffffffffa07f633a>]
btrfs_commit_transaction+0x66a/0xbd0 [btrfs]
[ 1401.201671] [<ffffffffa07f0f48>]
transaction_kthread+0x208/0x270 [btrfs]
[ 1401.201680] [<ffffffff810d1351>]
kthread+0x101/0x120
[ 1401.201683] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.201686] HARDIRQ-ON-R at:
[ 1401.201687] [<ffffffff8110705c>]
__lock_acquire+0x53c/0x1ba0
[ 1401.201690] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201692] [<ffffffff81864331>]
down_read+0x51/0xa0
[ 1401.201695] [<ffffffffa07eab4a>]
caching_kthread+0xda/0x360 [btrfs]
[ 1401.201703] [<ffffffff810d1351>]
kthread+0x101/0x120
[ 1401.201705] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.201708] SOFTIRQ-ON-W at:
[ 1401.201709] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.201712] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201714] [<ffffffff818643da>]
down_write+0x5a/0xc0
[ 1401.201716] [<ffffffffa07dd386>]
btrfs_prepare_extent_commit+0x36/0x120 [btrfs]
[ 1401.201724] [<ffffffffa07f633a>]
btrfs_commit_transaction+0x66a/0xbd0 [btrfs]
[ 1401.201733] [<ffffffffa07f0f48>]
transaction_kthread+0x208/0x270 [btrfs]
[ 1401.201741] [<ffffffff810d1351>]
kthread+0x101/0x120
[ 1401.201743] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.201745] SOFTIRQ-ON-R at:
[ 1401.201747] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.201749] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201751] [<ffffffff81864331>]
down_read+0x51/0xa0
[ 1401.201754] [<ffffffffa07eab4a>]
caching_kthread+0xda/0x360 [btrfs]
[ 1401.201762] [<ffffffff810d1351>]
kthread+0x101/0x120
[ 1401.201764] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.201766] RECLAIM_FS-ON-W at:
[ 1401.201768] [<ffffffff811065e9>]
mark_held_locks+0x79/0xa0
[ 1401.201770] [<ffffffff8110999b>]
lockdep_trace_alloc+0x7b/0xd0
[ 1401.201773] [<ffffffff812474e6>]
kmem_cache_alloc_trace+0x36/0x320
[ 1401.201776] [<ffffffff810d1116>]
kthread_create_on_node+0x116/0x250
[ 1401.201778] [<ffffffffa07eb68b>]
start_caching+0xdb/0x180 [btrfs]
[ 1401.201786] [<ffffffffa07eb7cb>]
btrfs_return_ino+0x9b/0xe0 [btrfs]
[ 1401.201794] [<ffffffffa0802d21>]
btrfs_evict_inode+0x621/0x660 [btrfs]
[ 1401.201804] [<ffffffff8128c57f>]
evict+0xaf/0x180
[ 1401.201807] [<ffffffff8128c8d9>]
iput+0x229/0x2c0
[ 1401.201809] [<ffffffff81286608>]
__dentry_kill+0x178/0x1e0
[ 1401.201812] [<ffffffff812883a7>]
dput+0x2a7/0x3a0
[ 1401.201815] [<ffffffff81280c21>]
SyS_rename+0x311/0x3a0
[ 1401.201817] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.201820] INITIAL USE at:
[ 1401.201821] [<ffffffff811070cd>]
__lock_acquire+0x5ad/0x1ba0
[ 1401.201823] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201826] [<ffffffff818643da>]
down_write+0x5a/0xc0
[ 1401.201828] [<ffffffffa07dd386>]
btrfs_prepare_extent_commit+0x36/0x120 [btrfs]
[ 1401.201836] [<ffffffffa07f633a>]
btrfs_commit_transaction+0x66a/0xbd0 [btrfs]
[ 1401.201845] [<ffffffffa07f0f48>]
transaction_kthread+0x208/0x270 [btrfs]
[ 1401.201853] [<ffffffff810d1351>] kthread+0x101/0x120
[ 1401.201855] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.201857] }
[ 1401.201859] ... key at: [<ffffffffa08924a0>]
__key.49471+0x0/0xfffffffffffe3b60 [btrfs]
[ 1401.201868] ... acquired at:
[ 1401.201869] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.201871] [<ffffffff81864331>] down_read+0x51/0xa0
[ 1401.201874] [<ffffffffa07d743d>] caching_thread+0x10d/0x4c0 [btrfs]
[ 1401.201881] [<ffffffffa08294a0>]
btrfs_scrubparity_helper+0x190/0x530 [btrfs]
[ 1401.201892] [<ffffffffa082995e>] btrfs_cache_helper+0xe/0x10 [btrfs]
[ 1401.201902] [<ffffffff810c9e40>] process_one_work+0x230/0x6a0
[ 1401.201905] [<ffffffff810ca2fe>] worker_thread+0x4e/0x450
[ 1401.201907] [<ffffffff810d1351>] kthread+0x101/0x120
[ 1401.201909] [<ffffffff818673af>] ret_from_fork+0x3f/0x70
[ 1401.201913] -> (&caching_ctl->mutex){+.+...} ops: 1478 {
[ 1401.201917] HARDIRQ-ON-W at:
[ 1401.201918] [<ffffffff81107432>]
__lock_acquire+0x912/0x1ba0
[ 1401.201921] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.201923] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.201926] [<ffffffffa07d66cb>]
cache_block_group+0x1bb/0x3e0 [btrfs]
[ 1401.201933] [<ffffffffa07e2eb3>]
find_free_extent+0x8b3/0xfb0 [btrfs]
[ 1401.201941] [<ffffffffa07e3637>]
btrfs_reserve_extent+0x87/0x170 [btrfs]
[ 1401.201949] [<ffffffffa07e3826>]
btrfs_alloc_tree_block+0x106/0x4d0 [btrfs]
[ 1401.201956] [<ffffffffa07ca0d1>]
__btrfs_cow_block+0x141/0x590 [btrfs]
[ 1401.201963] [<ffffffffa07ca6b2>]
btrfs_cow_block+0x112/0x260 [btrfs]
[ 1401.201969] [<ffffffffa07ce3a9>]
btrfs_search_slot+0x1e9/0x9f0 [btrfs]
[ 1401.201976] [<ffffffffa07d04c1>]
btrfs_insert_empty_items+0x71/0xc0 [btrfs]
[ 1401.201983] [<ffffffffa07e75f2>]
insert_with_overflow+0x42/0x120 [btrfs]
[ 1401.201992] [<ffffffffa07e777d>]
btrfs_insert_xattr_item+0xad/0x1a0 [btrfs]
[ 1401.201999] [<ffffffffa08100bb>]
do_setxattr+0xdb/0x410 [btrfs]
[ 1401.202010] [<ffffffffa0810670>]
__btrfs_setxattr+0x80/0xf0 [btrfs]
[ 1401.202019] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202028] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202030] [<ffffffff81298799>]
vfs_setxattr+0xa9/0xb0
[ 1401.202032] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202034] [<ffffffff81298a7a>]
path_setxattr+0xaa/0xe0
[ 1401.202037] [<ffffffff81298c71>]
SyS_lsetxattr+0x11/0x20
[ 1401.202039] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202041] SOFTIRQ-ON-W at:
[ 1401.202043] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.202045] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202047] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202050] [<ffffffffa07d66cb>]
cache_block_group+0x1bb/0x3e0 [btrfs]
[ 1401.202057] [<ffffffffa07e2eb3>]
find_free_extent+0x8b3/0xfb0 [btrfs]
[ 1401.202065] [<ffffffffa07e3637>]
btrfs_reserve_extent+0x87/0x170 [btrfs]
[ 1401.202072] [<ffffffffa07e3826>]
btrfs_alloc_tree_block+0x106/0x4d0 [btrfs]
[ 1401.202079] [<ffffffffa07ca0d1>]
__btrfs_cow_block+0x141/0x590 [btrfs]
[ 1401.202086] [<ffffffffa07ca6b2>]
btrfs_cow_block+0x112/0x260 [btrfs]
[ 1401.202092] [<ffffffffa07ce3a9>]
btrfs_search_slot+0x1e9/0x9f0 [btrfs]
[ 1401.202099] [<ffffffffa07d04c1>]
btrfs_insert_empty_items+0x71/0xc0 [btrfs]
[ 1401.202106] [<ffffffffa07e75f2>]
insert_with_overflow+0x42/0x120 [btrfs]
[ 1401.202114] [<ffffffffa07e777d>]
btrfs_insert_xattr_item+0xad/0x1a0 [btrfs]
[ 1401.202121] [<ffffffffa08100bb>]
do_setxattr+0xdb/0x410 [btrfs]
[ 1401.202130] [<ffffffffa0810670>]
__btrfs_setxattr+0x80/0xf0 [btrfs]
[ 1401.202139] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202148] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202150] [<ffffffff81298799>]
vfs_setxattr+0xa9/0xb0
[ 1401.202152] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202154] [<ffffffff81298a7a>]
path_setxattr+0xaa/0xe0
[ 1401.202156] [<ffffffff81298c71>]
SyS_lsetxattr+0x11/0x20
[ 1401.202158] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202161] INITIAL USE at:
[ 1401.202162] [<ffffffff811070cd>]
__lock_acquire+0x5ad/0x1ba0
[ 1401.202165] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202167] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202170] [<ffffffffa07d66cb>]
cache_block_group+0x1bb/0x3e0 [btrfs]
[ 1401.202177] [<ffffffffa07e2eb3>]
find_free_extent+0x8b3/0xfb0 [btrfs]
[ 1401.202185] [<ffffffffa07e3637>]
btrfs_reserve_extent+0x87/0x170 [btrfs]
[ 1401.202192] [<ffffffffa07e3826>]
btrfs_alloc_tree_block+0x106/0x4d0 [btrfs]
[ 1401.202199] [<ffffffffa07ca0d1>]
__btrfs_cow_block+0x141/0x590 [btrfs]
[ 1401.202205] [<ffffffffa07ca6b2>]
btrfs_cow_block+0x112/0x260 [btrfs]
[ 1401.202212] [<ffffffffa07ce3a9>]
btrfs_search_slot+0x1e9/0x9f0 [btrfs]
[ 1401.202219] [<ffffffffa07d04c1>]
btrfs_insert_empty_items+0x71/0xc0 [btrfs]
[ 1401.202226] [<ffffffffa07e75f2>]
insert_with_overflow+0x42/0x120 [btrfs]
[ 1401.202233] [<ffffffffa07e777d>]
btrfs_insert_xattr_item+0xad/0x1a0 [btrfs]
[ 1401.202241] [<ffffffffa08100bb>]
do_setxattr+0xdb/0x410 [btrfs]
[ 1401.202250] [<ffffffffa0810670>]
__btrfs_setxattr+0x80/0xf0 [btrfs]
[ 1401.202258] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202267] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202269] [<ffffffff81298799>]
vfs_setxattr+0xa9/0xb0
[ 1401.202271] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202273] [<ffffffff81298a7a>]
path_setxattr+0xaa/0xe0
[ 1401.202275] [<ffffffff81298c71>]
SyS_lsetxattr+0x11/0x20
[ 1401.202277] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202280] }
[ 1401.202281] ... key at: [<ffffffffa08923c8>]
__key.47663+0x0/0xfffffffffffe3c38 [btrfs]
[ 1401.202289] ... acquired at:
[ 1401.202290] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202292] [<ffffffff81863286>] mutex_lock_nested+0x86/0x400
[ 1401.202294] [<ffffffffa07d66cb>] cache_block_group+0x1bb/0x3e0 [btrfs]
[ 1401.202301] [<ffffffffa07e2eb3>] find_free_extent+0x8b3/0xfb0 [btrfs]
[ 1401.202308] [<ffffffffa07e3637>] btrfs_reserve_extent+0x87/0x170 [btrfs]
[ 1401.202316] [<ffffffffa07e3826>]
btrfs_alloc_tree_block+0x106/0x4d0 [btrfs]
[ 1401.202323] [<ffffffffa07ca0d1>] __btrfs_cow_block+0x141/0x590 [btrfs]
[ 1401.202329] [<ffffffffa07ca6b2>] btrfs_cow_block+0x112/0x260 [btrfs]
[ 1401.202336] [<ffffffffa07ce3a9>] btrfs_search_slot+0x1e9/0x9f0 [btrfs]
[ 1401.202342] [<ffffffffa07d04c1>]
btrfs_insert_empty_items+0x71/0xc0 [btrfs]
[ 1401.202349] [<ffffffffa07e75f2>] insert_with_overflow+0x42/0x120 [btrfs]
[ 1401.202356] [<ffffffffa07e777d>]
btrfs_insert_xattr_item+0xad/0x1a0 [btrfs]
[ 1401.202364] [<ffffffffa08100bb>] do_setxattr+0xdb/0x410 [btrfs]
[ 1401.202373] [<ffffffffa0810670>] __btrfs_setxattr+0x80/0xf0 [btrfs]
[ 1401.202381] [<ffffffffa0810b1d>] btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202389] [<ffffffff812985fc>] __vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202391] [<ffffffff81298799>] vfs_setxattr+0xa9/0xb0
[ 1401.202393] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202395] [<ffffffff81298a7a>] path_setxattr+0xaa/0xe0
[ 1401.202397] [<ffffffff81298c71>] SyS_lsetxattr+0x11/0x20
[ 1401.202399] [<ffffffff81867032>] entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202402] -> (&found->groups_sem){++++..} ops: 237040 {
[ 1401.202406] HARDIRQ-ON-W at:
[ 1401.202407] [<ffffffff81107432>]
__lock_acquire+0x912/0x1ba0
[ 1401.202409] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202412] [<ffffffff818643da>] down_write+0x5a/0xc0
[ 1401.202414] [<ffffffffa07de096>]
__link_block_group+0x36/0x130 [btrfs]
[ 1401.202422] [<ffffffffa07df8b5>]
btrfs_read_block_groups+0x2c5/0x650 [btrfs]
[ 1401.202429] [<ffffffffa07f2cd2>]
open_ctree+0x1992/0x25c0 [btrfs]
[ 1401.202437] [<ffffffffa07c64c5>]
btrfs_mount+0x945/0xa60 [btrfs]
[ 1401.202444] [<ffffffff81271bc8>] mount_fs+0x38/0x170
[ 1401.202446] [<ffffffff81291c1b>]
vfs_kern_mount+0x6b/0x150
[ 1401.202449] [<ffffffff81294ac5>] do_mount+0x245/0xe60
[ 1401.202451] [<ffffffff81295a2f>] SyS_mount+0x9f/0x100
[ 1401.202454] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202456] HARDIRQ-ON-R at:
[ 1401.202457] [<ffffffff8110705c>]
__lock_acquire+0x53c/0x1ba0
[ 1401.202460] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202462] [<ffffffff81864331>] down_read+0x51/0xa0
[ 1401.202464] [<ffffffffa07ee4c6>]
btrfs_calc_num_tolerated_disk_barrier_failures+0x166/0x250 [btrfs]
[ 1401.202473] [<ffffffffa07f2cea>]
open_ctree+0x19aa/0x25c0 [btrfs]
[ 1401.202481] [<ffffffffa07c64c5>]
btrfs_mount+0x945/0xa60 [btrfs]
[ 1401.202487] [<ffffffff81271bc8>] mount_fs+0x38/0x170
[ 1401.202489] [<ffffffff81291c1b>]
vfs_kern_mount+0x6b/0x150
[ 1401.202492] [<ffffffff81294ac5>] do_mount+0x245/0xe60
[ 1401.202494] [<ffffffff81295a2f>] SyS_mount+0x9f/0x100
[ 1401.202496] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202499] SOFTIRQ-ON-W at:
[ 1401.202500] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.202502] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202504] [<ffffffff818643da>] down_write+0x5a/0xc0
[ 1401.202507] [<ffffffffa07de096>]
__link_block_group+0x36/0x130 [btrfs]
[ 1401.202514] [<ffffffffa07df8b5>]
btrfs_read_block_groups+0x2c5/0x650 [btrfs]
[ 1401.202521] [<ffffffffa07f2cd2>]
open_ctree+0x1992/0x25c0 [btrfs]
[ 1401.202529] [<ffffffffa07c64c5>]
btrfs_mount+0x945/0xa60 [btrfs]
[ 1401.202535] [<ffffffff81271bc8>] mount_fs+0x38/0x170
[ 1401.202537] [<ffffffff81291c1b>]
vfs_kern_mount+0x6b/0x150
[ 1401.202539] [<ffffffff81294ac5>] do_mount+0x245/0xe60
[ 1401.202541] [<ffffffff81295a2f>] SyS_mount+0x9f/0x100
[ 1401.202544] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202546] SOFTIRQ-ON-R at:
[ 1401.202547] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.202549] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202552] [<ffffffff81864331>] down_read+0x51/0xa0
[ 1401.202554] [<ffffffffa07ee4c6>]
btrfs_calc_num_tolerated_disk_barrier_failures+0x166/0x250 [btrfs]
[ 1401.202562] [<ffffffffa07f2cea>]
open_ctree+0x19aa/0x25c0 [btrfs]
[ 1401.202569] [<ffffffffa07c64c5>]
btrfs_mount+0x945/0xa60 [btrfs]
[ 1401.202575] [<ffffffff81271bc8>] mount_fs+0x38/0x170
[ 1401.202577] [<ffffffff81291c1b>]
vfs_kern_mount+0x6b/0x150
[ 1401.202579] [<ffffffff81294ac5>] do_mount+0x245/0xe60
[ 1401.202582] [<ffffffff81295a2f>] SyS_mount+0x9f/0x100
[ 1401.202584] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202586] INITIAL USE at:
[ 1401.202588] [<ffffffff811070cd>]
__lock_acquire+0x5ad/0x1ba0
[ 1401.202590] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202592] [<ffffffff818643da>] down_write+0x5a/0xc0
[ 1401.202594] [<ffffffffa07de096>]
__link_block_group+0x36/0x130 [btrfs]
[ 1401.202602] [<ffffffffa07df8b5>]
btrfs_read_block_groups+0x2c5/0x650 [btrfs]
[ 1401.202609] [<ffffffffa07f2cd2>]
open_ctree+0x1992/0x25c0 [btrfs]
[ 1401.202617] [<ffffffffa07c64c5>]
btrfs_mount+0x945/0xa60 [btrfs]
[ 1401.202623] [<ffffffff81271bc8>] mount_fs+0x38/0x170
[ 1401.202626] [<ffffffff81291c1b>]
vfs_kern_mount+0x6b/0x150
[ 1401.202628] [<ffffffff81294ac5>] do_mount+0x245/0xe60
[ 1401.202630] [<ffffffff81295a2f>] SyS_mount+0x9f/0x100
[ 1401.202632] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202635] }
[ 1401.202636] ... key at: [<ffffffffa08923b0>]
__key.48555+0x0/0xfffffffffffe3c50 [btrfs]
[ 1401.202642] ... acquired at:
[ 1401.202643] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202645] [<ffffffff81864331>] down_read+0x51/0xa0
[ 1401.202647] [<ffffffffa07e2fa9>] find_free_extent+0x9a9/0xfb0 [btrfs]
[ 1401.202654] [<ffffffffa07e3637>] btrfs_reserve_extent+0x87/0x170 [btrfs]
[ 1401.202660] [<ffffffffa07e3826>]
btrfs_alloc_tree_block+0x106/0x4d0 [btrfs]
[ 1401.202667] [<ffffffffa07ca0d1>] __btrfs_cow_block+0x141/0x590 [btrfs]
[ 1401.202673] [<ffffffffa07ca6b2>] btrfs_cow_block+0x112/0x260 [btrfs]
[ 1401.202680] [<ffffffffa07ce3a9>] btrfs_search_slot+0x1e9/0x9f0 [btrfs]
[ 1401.202687] [<ffffffffa07ea85e>] btrfs_lookup_inode+0x3e/0xc0 [btrfs]
[ 1401.202695] [<ffffffffa084e709>]
__btrfs_update_delayed_inode+0x69/0x210 [btrfs]
[ 1401.202706] [<ffffffffa084fb71>]
btrfs_commit_inode_delayed_inode+0x121/0x130 [btrfs]
[ 1401.202716] [<ffffffffa0802ad0>] btrfs_evict_inode+0x3d0/0x660 [btrfs]
[ 1401.202725] [<ffffffff8128c57f>] evict+0xaf/0x180
[ 1401.202727] [<ffffffff8128c8d9>] iput+0x229/0x2c0
[ 1401.202729] [<ffffffff81286608>] __dentry_kill+0x178/0x1e0
[ 1401.202732] [<ffffffff812883a7>] dput+0x2a7/0x3a0
[ 1401.202734] [<ffffffff81280c21>] SyS_rename+0x311/0x3a0
[ 1401.202737] [<ffffffff81867032>] entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202741] -> (&delayed_node->mutex){+.+.-.} ops: 1388847 {
[ 1401.202745] HARDIRQ-ON-W at:
[ 1401.202746] [<ffffffff81107432>]
__lock_acquire+0x912/0x1ba0
[ 1401.202749] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202751] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202754] [<ffffffffa08508d9>]
btrfs_delayed_update_inode+0x49/0x600 [btrfs]
[ 1401.202764] [<ffffffffa07fc2af>]
btrfs_update_inode+0x8f/0x100 [btrfs]
[ 1401.202774] [<ffffffffa08106bc>]
__btrfs_setxattr+0xcc/0xf0 [btrfs]
[ 1401.202783] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202792] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202794] [<ffffffff81298799>] vfs_setxattr+0xa9/0xb0
[ 1401.202796] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202799] [<ffffffff81298a7a>] path_setxattr+0xaa/0xe0
[ 1401.202801] [<ffffffff81298c71>] SyS_lsetxattr+0x11/0x20
[ 1401.202803] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202805] SOFTIRQ-ON-W at:
[ 1401.202807] [<ffffffff8110745e>]
__lock_acquire+0x93e/0x1ba0
[ 1401.202809] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202811] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202814] [<ffffffffa08508d9>]
btrfs_delayed_update_inode+0x49/0x600 [btrfs]
[ 1401.202825] [<ffffffffa07fc2af>]
btrfs_update_inode+0x8f/0x100 [btrfs]
[ 1401.202834] [<ffffffffa08106bc>]
__btrfs_setxattr+0xcc/0xf0 [btrfs]
[ 1401.202843] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202851] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202853] [<ffffffff81298799>] vfs_setxattr+0xa9/0xb0
[ 1401.202855] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202857] [<ffffffff81298a7a>] path_setxattr+0xaa/0xe0
[ 1401.202860] [<ffffffff81298c71>] SyS_lsetxattr+0x11/0x20
[ 1401.202862] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202864] IN-RECLAIM_FS-W at:
[ 1401.202866] [<ffffffff8110747f>]
__lock_acquire+0x95f/0x1ba0
[ 1401.202868] [<ffffffff8110903e>]
lock_acquire+0xce/0x1c0
[ 1401.202870] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202873] [<ffffffffa084dccd>]
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.202883] [<ffffffffa084fba4>]
btrfs_remove_delayed_node+0x24/0x30 [btrfs]
[ 1401.202893] [<ffffffffa08029ac>]
btrfs_evict_inode+0x2ac/0x660 [btrfs]
[ 1401.202902] [<ffffffff8128c57f>] evict+0xaf/0x180
[ 1401.202904] [<ffffffff8128c687>]
dispose_list+0x37/0x60
[ 1401.202907] [<ffffffff8128d93a>]
prune_icache_sb+0x5a/0x80
[ 1401.202909] [<ffffffff8127148c>]
super_cache_scan+0x14c/0x1a0
[ 1401.202911] [<ffffffff811f54f3>]
shrink_slab.part.41+0x213/0x540
[ 1401.202914] [<ffffffff811fa176>]
shrink_zone+0x2b6/0x2c0
[ 1401.202917] [<ffffffff811fb661>] kswapd+0x571/0xb10
[ 1401.202919] [<ffffffff810d1351>] kthread+0x101/0x120
[ 1401.202921] [<ffffffff818673af>]
ret_from_fork+0x3f/0x70
[ 1401.202924] INITIAL USE at:
[ 1401.202925] [<ffffffff811070cd>]
__lock_acquire+0x5ad/0x1ba0
[ 1401.202927] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.202930] [<ffffffff81863286>]
mutex_lock_nested+0x86/0x400
[ 1401.202932] [<ffffffffa08508d9>]
btrfs_delayed_update_inode+0x49/0x600 [btrfs]
[ 1401.202942] [<ffffffffa07fc2af>]
btrfs_update_inode+0x8f/0x100 [btrfs]
[ 1401.202951] [<ffffffffa08106bc>]
__btrfs_setxattr+0xcc/0xf0 [btrfs]
[ 1401.202961] [<ffffffffa0810b1d>]
btrfs_setxattr+0x8d/0xe0 [btrfs]
[ 1401.202969] [<ffffffff812985fc>]
__vfs_setxattr_noperm+0xac/0x1a0
[ 1401.202972] [<ffffffff81298799>] vfs_setxattr+0xa9/0xb0
[ 1401.202974] [<ffffffff812988d9>] setxattr+0x139/0x230
[ 1401.202976] [<ffffffff81298a7a>] path_setxattr+0xaa/0xe0
[ 1401.202978] [<ffffffff81298c71>] SyS_lsetxattr+0x11/0x20
[ 1401.202980] [<ffffffff81867032>]
entry_SYSCALL_64_fastpath+0x12/0x76
[ 1401.202983] }
[ 1401.202984] ... key at: [<ffffffffa08963b8>]
__key.46552+0x0/0xfffffffffffdfc48 [btrfs]
[ 1401.202991] ... acquired at:
[ 1401.202992] [<ffffffff8110546d>] check_usage_forwards+0x15d/0x170
[ 1401.202995] [<ffffffff8110628a>] mark_lock+0x33a/0x620
[ 1401.202997] [<ffffffff8110747f>] __lock_acquire+0x95f/0x1ba0
[ 1401.203000] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.203002] [<ffffffff81863286>] mutex_lock_nested+0x86/0x400
[ 1401.203004] [<ffffffffa084dccd>]
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.203014] [<ffffffffa084fba4>]
btrfs_remove_delayed_node+0x24/0x30 [btrfs]
[ 1401.203024] [<ffffffffa08029ac>] btrfs_evict_inode+0x2ac/0x660 [btrfs]
[ 1401.203033] [<ffffffff8128c57f>] evict+0xaf/0x180
[ 1401.203036] [<ffffffff8128c687>] dispose_list+0x37/0x60
[ 1401.203038] [<ffffffff8128d93a>] prune_icache_sb+0x5a/0x80
[ 1401.203040] [<ffffffff8127148c>] super_cache_scan+0x14c/0x1a0
[ 1401.203042] [<ffffffff811f54f3>] shrink_slab.part.41+0x213/0x540
[ 1401.203045] [<ffffffff811fa176>] shrink_zone+0x2b6/0x2c0
[ 1401.203047] [<ffffffff811fb661>] kswapd+0x571/0xb10
[ 1401.203050] [<ffffffff810d1351>] kthread+0x101/0x120
[ 1401.203052] [<ffffffff818673af>] ret_from_fork+0x3f/0x70
[ 1401.203055]
stack backtrace:
[ 1401.203059] CPU: 1 PID: 80 Comm: kswapd0 Not tainted
4.3.5-300.fc23.x86_64+debug #1
[ 1401.203060] Hardware name: Gigabyte Technology Co., Ltd.
Z87M-D3H/Z87M-D3H, BIOS F11 08/12/2014
[ 1401.203062] 0000000000000000 0000000020b8f59d ffff88009c51f760
ffffffff8141c3f9
[ 1401.203066] ffffffff82f54e80 ffff88009c51f7a0 ffffffff811dd2dc
ffff88009c518998
[ 1401.203069] ffff88009c518998 ffff88009c518000 ffffffff81c7e381
0000000000000000
[ 1401.203072] Call Trace:
[ 1401.203077] [<ffffffff8141c3f9>] dump_stack+0x4b/0x72
[ 1401.203080] [<ffffffff811dd2dc>] print_irq_inversion_bug.part.40+0x1a4/0x1b0
[ 1401.203083] [<ffffffff8110546d>] check_usage_forwards+0x15d/0x170
[ 1401.203085] [<ffffffff8110628a>] mark_lock+0x33a/0x620
[ 1401.203088] [<ffffffff81105310>] ?
print_shortest_lock_dependencies+0x1a0/0x1a0
[ 1401.203090] [<ffffffff8110747f>] __lock_acquire+0x95f/0x1ba0
[ 1401.203092] [<ffffffff811076f7>] ? __lock_acquire+0xbd7/0x1ba0
[ 1401.203096] [<ffffffff810e5e8c>] ? local_clock+0x1c/0x20
[ 1401.203099] [<ffffffff8110903e>] lock_acquire+0xce/0x1c0
[ 1401.203108] [<ffffffffa084dccd>] ?
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.203111] [<ffffffff81863286>] mutex_lock_nested+0x86/0x400
[ 1401.203120] [<ffffffffa084dccd>] ?
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.203123] [<ffffffff81025c09>] ? sched_clock+0x9/0x10
[ 1401.203132] [<ffffffffa084dccd>] ?
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.203135] [<ffffffff8112515d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 1401.203143] [<ffffffffa084dccd>]
__btrfs_release_delayed_node+0x3d/0x1c0 [btrfs]
[ 1401.203152] [<ffffffffa084fba4>] btrfs_remove_delayed_node+0x24/0x30 [btrfs]
[ 1401.203161] [<ffffffffa08029ac>] btrfs_evict_inode+0x2ac/0x660 [btrfs]
[ 1401.203164] [<ffffffff8128c57f>] evict+0xaf/0x180
[ 1401.203166] [<ffffffff8128c687>] dispose_list+0x37/0x60
[ 1401.203168] [<ffffffff8128d93a>] prune_icache_sb+0x5a/0x80
[ 1401.203170] [<ffffffff8127148c>] super_cache_scan+0x14c/0x1a0
[ 1401.203172] [<ffffffff811f54f3>] shrink_slab.part.41+0x213/0x540
[ 1401.203175] [<ffffffff8112515d>] ? debug_lockdep_rcu_enabled+0x1d/0x20
[ 1401.203178] [<ffffffff811fa176>] shrink_zone+0x2b6/0x2c0
[ 1401.203180] [<ffffffff811fb661>] kswapd+0x571/0xb10
[ 1401.203183] [<ffffffff811fb0f0>] ? mem_cgroup_shrink_node_zone+0x300/0x300
[ 1401.203185] [<ffffffff810d1351>] kthread+0x101/0x120
[ 1401.203188] [<ffffffff81106739>] ? trace_hardirqs_on_caller+0x129/0x1b0
[ 1401.203191] [<ffffffff810d1250>] ? kthread_create_on_node+0x250/0x250
[ 1401.203193] [<ffffffff818673af>] ret_from_fork+0x3f/0x70
[ 1401.203195] [<ffffffff810d1250>] ? kthread_create_on_node+0x250/0x250
[ 1410.976378] kworker/dying (151) used greatest stack depth: 9768 bytes left
--
Best Regards,
Mike Gavrilov.
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2017-10-11 13:16 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2017-10-10 18:51 possible irq lock inversion dependency detected René van Dorst
2017-10-11 1:19 ` Jason A. Donenfeld
2017-10-11 12:49 ` René van Dorst
2017-10-11 12:51 ` Jason A. Donenfeld
2017-10-11 13:30 ` René van Dorst
2017-10-11 13:46 ` Jason A. Donenfeld
-- strict thread matches above, loose matches on Subject: below --
2016-02-06 10:07 Михаил Гаврилов
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.