From: Roman Mamedov <rm@romanrm.net>
To: Chris Murphy <lists@colorremedies.com>
Cc: Btrfs BTRFS <linux-btrfs@vger.kernel.org>
Subject: Reproduced deadlock after upgrade from 3.18 to 4.1 or 4.3 (+ more info)
Date: Sun, 10 Jan 2016 05:31:19 +0500 [thread overview]
Message-ID: <20160110053119.45e05246@natsu> (raw)
In-Reply-To: <CAJCQCtRTNgUFnjGyF6wBeiX2LzMjO8Avc8xGb9NAFLnvgGyM3Q@mail.gmail.com>
[-- Attachment #1.1: Type: text/plain, Size: 22532 bytes --]
On Fri, 25 Dec 2015 21:34:43 -0700
Chris Murphy <lists@colorremedies.com> wrote:
> This could be an unintended regression, I'm not finding much related
> at all in recent history in the traces. I'd say reproduce and get a
> sysrq+w captured. Most of the traces are actually from rdiff-backup,
> but the first one is a kworker. So something happens and then due to
> the ensuing congestion it all just gets worse. Maybe it would have
> eventually recovered but once it's this congested it might have taken
> a really long time.
>
> I would then also try to reproduce with 4.2.8 or 4.3.3 because those
> have ~ 25% backports than made it to 4.1.15, so there's an off chance
> it's fixed there. But even better to just go straight to 4.4.rc6 if
> you can, because an unintended regression that's not known will likely
> happen in 4.4 and would need to be fixed now before it'd get
> backported anyway. *shrug*
Hello,
After this case I went back to 3.18.25, and the system worked fine for about 2
weeks more. However now I decided to try upgrading again, this time to 4.3.3 -
and hit the deadlock on the very first attempt to use the same script.
The script launches many rdiff-backup processes at once to prune old backups,
so it's heavy concurrent load of directory listing and file deletion.
In dmesg I got the following, sysrq+w is attached (I don't think it managed to fit
into dmesg from beginning, but still seems to be some useful stuff there)
[ 7676.096403] INFO: task kworker/u16:10:5653 blocked for more than 120 seconds.
[ 7676.096429] Not tainted 4.3.3-rm1+ #101
[ 7676.096438] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.096452] kworker/u16:10 D ffff88082ecd5cc0 0 5653 2 0x00000000
[ 7676.096496] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
[ 7676.096500] ffff8807512979b8 0000000000000046 ffff88080af10000 ffff8807ff411d40
[ 7676.096505] ffff880751298000 00000000ffffff00 ffff8807ff411d40 ffff8807ff411d40
[ 7676.096510] ffff8800ad8e9928 ffff8807512979d0 ffffffff815ca143 ffff8800ad8e9990
[ 7676.096515] Call Trace:
[ 7676.096525] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.096555] [<ffffffffa036c26c>] btrfs_tree_read_lock+0xec/0x140 [btrfs]
[ 7676.096561] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.096579] [<ffffffffa0304644>] btrfs_read_lock_root_node+0x34/0x50 [btrfs]
[ 7676.096597] [<ffffffffa03099d4>] btrfs_search_slot+0x744/0x9f0 [btrfs]
[ 7676.096602] [<ffffffff8130900e>] ? cpumask_next_and+0x2e/0x40
[ 7676.096623] [<ffffffffa03231e7>] btrfs_lookup_file_extent+0x47/0x70 [btrfs]
[ 7676.096650] [<ffffffffa03447bc>] __btrfs_drop_extents+0x19c/0xf10 [btrfs]
[ 7676.096679] [<ffffffffa034e681>] ? __set_extent_bit+0x221/0x5a0 [btrfs]
[ 7676.096685] [<ffffffff811cde2b>] ? kmem_cache_alloc+0x11b/0x130
[ 7676.096701] [<ffffffffa030439a>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
[ 7676.096726] [<ffffffffa03329f4>] insert_reserved_file_extent.constprop.63+0xb4/0x320 [btrfs]
[ 7676.096752] [<ffffffffa03397d4>] btrfs_finish_ordered_io+0x2f4/0x650 [btrfs]
[ 7676.096759] [<ffffffff81020989>] ? sched_clock+0x9/0x10
[ 7676.096783] [<ffffffffa0339db5>] finish_ordered_fn+0x15/0x20 [btrfs]
[ 7676.096811] [<ffffffffa03627bf>] normal_work_helper+0xbf/0x250 [btrfs]
[ 7676.096839] [<ffffffffa0362ae2>] btrfs_endio_write_helper+0x12/0x20 [btrfs]
[ 7676.096845] [<ffffffff81092e80>] process_one_work+0x150/0x3f0
[ 7676.096849] [<ffffffff81093929>] worker_thread+0x69/0x470
[ 7676.096853] [<ffffffff810938c0>] ? rescuer_thread+0x310/0x310
[ 7676.096858] [<ffffffff8109901a>] kthread+0xea/0x100
[ 7676.096863] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.096868] [<ffffffff815ce74f>] ret_from_fork+0x3f/0x70
[ 7676.096873] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.096927] INFO: task kworker/u16:7:10989 blocked for more than 120 seconds.
[ 7676.096938] Not tainted 4.3.3-rm1+ #101
[ 7676.096946] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.096958] kworker/u16:7 D 0000000000000004 0 10989 2 0x00000000
[ 7676.096990] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
[ 7676.096993] ffff8804ec65b9b8 0000000000000046 ffff8807ffee57c0 ffff88066ed59d40
[ 7676.096998] ffff8804ec65c000 00000000ffffff00 ffff88066ed59d40 ffff88066ed59d40
[ 7676.097002] ffff8800ad8e9928 ffff8804ec65b9d0 ffffffff815ca143 ffff8800ad8e9990
[ 7676.097007] Call Trace:
[ 7676.097012] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.097040] [<ffffffffa036c26c>] btrfs_tree_read_lock+0xec/0x140 [btrfs]
[ 7676.097045] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.097062] [<ffffffffa0304644>] btrfs_read_lock_root_node+0x34/0x50 [btrfs]
[ 7676.097079] [<ffffffffa03099d4>] btrfs_search_slot+0x744/0x9f0 [btrfs]
[ 7676.097101] [<ffffffffa03231e7>] btrfs_lookup_file_extent+0x47/0x70 [btrfs]
[ 7676.097127] [<ffffffffa03447bc>] __btrfs_drop_extents+0x19c/0xf10 [btrfs]
[ 7676.097132] [<ffffffff811ce05f>] ? __slab_free.isra.69+0x7f/0x1a0
[ 7676.097161] [<ffffffffa034e681>] ? __set_extent_bit+0x221/0x5a0 [btrfs]
[ 7676.097166] [<ffffffff811cde2b>] ? kmem_cache_alloc+0x11b/0x130
[ 7676.097183] [<ffffffffa030439a>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
[ 7676.097207] [<ffffffffa03329f4>] insert_reserved_file_extent.constprop.63+0xb4/0x320 [btrfs]
[ 7676.097232] [<ffffffffa03397d4>] btrfs_finish_ordered_io+0x2f4/0x650 [btrfs]
[ 7676.097257] [<ffffffffa0339db5>] finish_ordered_fn+0x15/0x20 [btrfs]
[ 7676.097284] [<ffffffffa03627bf>] normal_work_helper+0xbf/0x250 [btrfs]
[ 7676.097312] [<ffffffffa0362ae2>] btrfs_endio_write_helper+0x12/0x20 [btrfs]
[ 7676.097316] [<ffffffff81092e80>] process_one_work+0x150/0x3f0
[ 7676.097320] [<ffffffff81093929>] worker_thread+0x69/0x470
[ 7676.097324] [<ffffffff810938c0>] ? rescuer_thread+0x310/0x310
[ 7676.097329] [<ffffffff8109901a>] kthread+0xea/0x100
[ 7676.097333] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.097338] [<ffffffff815ce74f>] ret_from_fork+0x3f/0x70
[ 7676.097343] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.097347] INFO: task kworker/u16:9:10992 blocked for more than 120 seconds.
[ 7676.097357] Not tainted 4.3.3-rm1+ #101
[ 7676.097365] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.097379] kworker/u16:9 D ffff88082ec15cc0 0 10992 2 0x00000000
[ 7676.097410] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
[ 7676.097413] ffff8804e56039b8 0000000000000046 ffffffff81a14540 ffff8807055e3a80
[ 7676.097418] ffff8804e5604000 00000000ffffff00 ffff8807055e3a80 ffff8807055e3a80
[ 7676.097422] ffff8800ad8e9928 ffff8804e56039d0 ffffffff815ca143 ffff8800ad8e9990
[ 7676.097427] Call Trace:
[ 7676.097432] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.097459] [<ffffffffa036c26c>] btrfs_tree_read_lock+0xec/0x140 [btrfs]
[ 7676.097464] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.097480] [<ffffffffa0304644>] btrfs_read_lock_root_node+0x34/0x50 [btrfs]
[ 7676.097497] [<ffffffffa03099d4>] btrfs_search_slot+0x744/0x9f0 [btrfs]
[ 7676.097504] [<ffffffff810a3d35>] ? ttwu_do_activate.constprop.91+0x65/0x70
[ 7676.097525] [<ffffffffa03231e7>] btrfs_lookup_file_extent+0x47/0x70 [btrfs]
[ 7676.097551] [<ffffffffa03447bc>] __btrfs_drop_extents+0x19c/0xf10 [btrfs]
[ 7676.097579] [<ffffffffa034e681>] ? __set_extent_bit+0x221/0x5a0 [btrfs]
[ 7676.097585] [<ffffffff811cde2b>] ? kmem_cache_alloc+0x11b/0x130
[ 7676.097601] [<ffffffffa030439a>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
[ 7676.097625] [<ffffffffa03329f4>] insert_reserved_file_extent.constprop.63+0xb4/0x320 [btrfs]
[ 7676.097650] [<ffffffffa03397d4>] btrfs_finish_ordered_io+0x2f4/0x650 [btrfs]
[ 7676.097675] [<ffffffffa0339db5>] finish_ordered_fn+0x15/0x20 [btrfs]
[ 7676.097703] [<ffffffffa03627bf>] normal_work_helper+0xbf/0x250 [btrfs]
[ 7676.097730] [<ffffffffa0362ae2>] btrfs_endio_write_helper+0x12/0x20 [btrfs]
[ 7676.097735] [<ffffffff81092e80>] process_one_work+0x150/0x3f0
[ 7676.097739] [<ffffffff81093929>] worker_thread+0x69/0x470
[ 7676.097742] [<ffffffff810938c0>] ? rescuer_thread+0x310/0x310
[ 7676.097747] [<ffffffff8109901a>] kthread+0xea/0x100
[ 7676.097752] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.097757] [<ffffffff815ce74f>] ret_from_fork+0x3f/0x70
[ 7676.097762] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.097766] INFO: task kworker/u16:14:10994 blocked for more than 120 seconds.
[ 7676.097779] Not tainted 4.3.3-rm1+ #101
[ 7676.097787] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.099024] kworker/u16:14 D ffff88082ec55cc0 0 10994 2 0x00000000
[ 7676.099054] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs]
[ 7676.099057] ffff88076865b9b8 0000000000000046 ffff88080aefba80 ffff8807bfb18000
[ 7676.099062] ffff88076865c000 00000000ffffff00 ffff8807bfb18000 ffff8807bfb18000
[ 7676.099066] ffff8800ad8e9928 ffff88076865b9d0 ffffffff815ca143 ffff8800ad8e9990
[ 7676.099071] Call Trace:
[ 7676.099075] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.099103] [<ffffffffa036c26c>] btrfs_tree_read_lock+0xec/0x140 [btrfs]
[ 7676.099107] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.099124] [<ffffffffa0304644>] btrfs_read_lock_root_node+0x34/0x50 [btrfs]
[ 7676.099144] [<ffffffffa03099d4>] btrfs_search_slot+0x744/0x9f0 [btrfs]
[ 7676.099165] [<ffffffffa03231e7>] btrfs_lookup_file_extent+0x47/0x70 [btrfs]
[ 7676.099190] [<ffffffffa03447bc>] __btrfs_drop_extents+0x19c/0xf10 [btrfs]
[ 7676.099219] [<ffffffffa034e681>] ? __set_extent_bit+0x221/0x5a0 [btrfs]
[ 7676.099224] [<ffffffff811cde2b>] ? kmem_cache_alloc+0x11b/0x130
[ 7676.099240] [<ffffffffa030439a>] ? btrfs_alloc_path+0x1a/0x20 [btrfs]
[ 7676.099265] [<ffffffffa03329f4>] insert_reserved_file_extent.constprop.63+0xb4/0x320 [btrfs]
[ 7676.099290] [<ffffffffa03397d4>] btrfs_finish_ordered_io+0x2f4/0x650 [btrfs]
[ 7676.099315] [<ffffffffa0339db5>] finish_ordered_fn+0x15/0x20 [btrfs]
[ 7676.099343] [<ffffffffa03627bf>] normal_work_helper+0xbf/0x250 [btrfs]
[ 7676.099371] [<ffffffffa0362ae2>] btrfs_endio_write_helper+0x12/0x20 [btrfs]
[ 7676.099375] [<ffffffff81092e80>] process_one_work+0x150/0x3f0
[ 7676.099380] [<ffffffff81093929>] worker_thread+0x69/0x470
[ 7676.099384] [<ffffffff810938c0>] ? rescuer_thread+0x310/0x310
[ 7676.099388] [<ffffffff8109901a>] kthread+0xea/0x100
[ 7676.099393] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.099398] [<ffffffff815ce74f>] ret_from_fork+0x3f/0x70
[ 7676.099403] [<ffffffff81098f30>] ? kthread_park+0x60/0x60
[ 7676.099412] INFO: task rdiff-backup:17190 blocked for more than 120 seconds.
[ 7676.099422] Not tainted 4.3.3-rm1+ #101
[ 7676.099430] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.099443] rdiff-backup D 0000000000000006 0 17190 17188 0x00000000
[ 7676.099448] ffff8804e50c7cd0 0000000000000082 ffff88047d961d40 ffff88015a480000
[ 7676.099452] ffff8804e50c8000 0000000000000012 ffff88080946aa98 ffff88080946aad8
[ 7676.099457] ffff88080946ab20 ffff8804e50c7ce8 ffffffff815ca143 ffff88080946a800
[ 7676.099461] Call Trace:
[ 7676.099466] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.099493] [<ffffffffa036d299>] wait_log_commit+0xe9/0x110 [btrfs]
[ 7676.099498] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.099526] [<ffffffffa0372d5a>] btrfs_sync_log+0x3ea/0xac0 [btrfs]
[ 7676.099531] [<ffffffff81200701>] ? dput+0xc1/0x240
[ 7676.099559] [<ffffffffa0373a15>] ? btrfs_log_dentry_safe+0x75/0x90 [btrfs]
[ 7676.099585] [<ffffffffa034728e>] btrfs_sync_file+0x2ee/0x350 [btrfs]
[ 7676.099591] [<ffffffff8121ce76>] vfs_fsync_range+0x46/0xc0
[ 7676.099596] [<ffffffff811e75ab>] ? do_sys_open+0x1bb/0x240
[ 7676.099600] [<ffffffff8121cf54>] do_fsync+0x44/0x70
[ 7676.099604] [<ffffffff8121d200>] SyS_fsync+0x10/0x20
[ 7676.099610] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
[ 7676.099614] INFO: task rdiff-backup:17227 blocked for more than 120 seconds.
[ 7676.099624] Not tainted 4.3.3-rm1+ #101
[ 7676.099632] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.099644] rdiff-backup D ffff88082ecd5cc0 0 17227 17225 0x00000000
[ 7676.099649] ffff88015a73f870 0000000000000086 ffff88080af10000 ffff88014d29ba80
[ 7676.099654] ffff88015a740000 ffff88058b93cb58 ffff88058b93cb70 ffff88015a73f8b0
[ 7676.099658] ffff88058b93cb50 ffff88015a73f888 ffffffff815ca143 ffff88058b93caf0
[ 7676.099663] Call Trace:
[ 7676.099667] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.099695] [<ffffffffa036c579>] btrfs_tree_lock+0x79/0x210 [btrfs]
[ 7676.099699] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.099716] [<ffffffffa0304694>] btrfs_lock_root_node+0x34/0x50 [btrfs]
[ 7676.099733] [<ffffffffa0309b76>] btrfs_search_slot+0x8e6/0x9f0 [btrfs]
[ 7676.099751] [<ffffffffa030b738>] btrfs_insert_empty_items+0x78/0xd0 [btrfs]
[ 7676.099779] [<ffffffffa036fbe7>] overwrite_item+0xf7/0x5f0 [btrfs]
[ 7676.099805] [<ffffffffa03ac015>] log_dir_items+0x2c5/0x4c2 [btrfs]
[ 7676.099831] [<ffffffffa03ac27e>] log_directory_changes+0x6c/0xb4 [btrfs]
[ 7676.099857] [<ffffffffa03ace15>] btrfs_log_inode+0xb4f/0xbcf [btrfs]
[ 7676.099862] [<ffffffff81200701>] ? dput+0xc1/0x240
[ 7676.099890] [<ffffffffa0371d59>] btrfs_log_inode_parent+0x2c9/0xee0 [btrfs]
[ 7676.099896] [<ffffffff811f81d3>] ? putname+0x53/0x60
[ 7676.099919] [<ffffffffa032f221>] ? wait_current_trans.isra.21+0x31/0x120 [btrfs]
[ 7676.099924] [<ffffffff811cdd3d>] ? kmem_cache_alloc+0x2d/0x130
[ 7676.099947] [<ffffffffa032ece5>] ? join_transaction.isra.15+0x25/0x440 [btrfs]
[ 7676.099975] [<ffffffffa0373a0a>] btrfs_log_dentry_safe+0x6a/0x90 [btrfs]
[ 7676.100001] [<ffffffffa03471dd>] btrfs_sync_file+0x23d/0x350 [btrfs]
[ 7676.100007] [<ffffffff8121ce76>] vfs_fsync_range+0x46/0xc0
[ 7676.100011] [<ffffffff811e75ab>] ? do_sys_open+0x1bb/0x240
[ 7676.100015] [<ffffffff8121cf54>] do_fsync+0x44/0x70
[ 7676.100019] [<ffffffff8121d200>] SyS_fsync+0x10/0x20
[ 7676.100025] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
[ 7676.100029] INFO: task rdiff-backup:17230 blocked for more than 120 seconds.
[ 7676.100068] Not tainted 4.3.3-rm1+ #101
[ 7676.100076] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.100089] rdiff-backup D 0000000000000001 0 17230 17228 0x00000000
[ 7676.100093] ffff880467a4f9a8 0000000000000086 ffff880806d6ba80 ffff88070549ba80
[ 7676.100098] ffff880467a50000 00000000ffffff00 ffff88070549ba80 ffff88070549ba80
[ 7676.100102] ffff8800ad8e9928 ffff880467a4f9c0 ffffffff815ca143 ffff8800ad8e9990
[ 7676.100107] Call Trace:
[ 7676.100111] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.100139] [<ffffffffa036c26c>] btrfs_tree_read_lock+0xec/0x140 [btrfs]
[ 7676.100143] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.100160] [<ffffffffa0304644>] btrfs_read_lock_root_node+0x34/0x50 [btrfs]
[ 7676.100177] [<ffffffffa03099d4>] btrfs_search_slot+0x744/0x9f0 [btrfs]
[ 7676.100182] [<ffffffff812c8c11>] ? crypto_shash_update+0x41/0x100
[ 7676.100203] [<ffffffffa0322323>] btrfs_lookup_dir_item+0x83/0xd0 [btrfs]
[ 7676.100227] [<ffffffffa033dc06>] btrfs_lookup_dentry+0xc6/0x560 [btrfs]
[ 7676.100232] [<ffffffff8120209f>] ? __d_alloc+0x11f/0x170
[ 7676.100257] [<ffffffffa033e0b2>] btrfs_lookup+0x12/0x40 [btrfs]
[ 7676.100261] [<ffffffff811f220d>] lookup_real+0x1d/0x60
[ 7676.100266] [<ffffffff811f25c7>] __lookup_hash+0x47/0x70
[ 7676.100270] [<ffffffff811f4035>] walk_component+0x215/0x4d0
[ 7676.100275] [<ffffffff811f495f>] link_path_walk+0x17f/0x580
[ 7676.100279] [<ffffffff811f4e6c>] path_lookupat+0x7c/0x110
[ 7676.100284] [<ffffffff811f867e>] filename_lookup+0xbe/0x1a0
[ 7676.100290] [<ffffffff810b2bcb>] ? should_numa_migrate_memory+0x6b/0x150
[ 7676.100295] [<ffffffff811cdd3d>] ? kmem_cache_alloc+0x2d/0x130
[ 7676.100299] [<ffffffff811f8241>] ? getname_flags+0x61/0x210
[ 7676.100304] [<ffffffff811f884f>] user_path_at_empty+0x3f/0x50
[ 7676.100308] [<ffffffff811ed15b>] vfs_fstatat+0x5b/0xc0
[ 7676.100312] [<ffffffff811ed741>] SYSC_newlstat+0x31/0x60
[ 7676.100323] [<ffffffff8106603c>] ? __do_page_fault+0x1cc/0x410
[ 7676.100366] [<ffffffff81209724>] ? mntput+0x24/0x40
[ 7676.100370] [<ffffffff811eda0e>] SyS_newlstat+0xe/0x10
[ 7676.100376] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
[ 7676.100380] INFO: task rdiff-backup:17235 blocked for more than 120 seconds.
[ 7676.100391] Not tainted 4.3.3-rm1+ #101
[ 7676.100401] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.100426] rdiff-backup D ffff88082edd5cc0 0 17235 17233 0x00000000
[ 7676.100474] ffff88014d22bcd0 0000000000000082 ffff88080af30000 ffff88014d29d7c0
[ 7676.100547] ffff88014d22c000 0000000000000012 ffff88080946aa98 ffff88080946aad8
[ 7676.100621] ffff88080946ab20 ffff88014d22bce8 ffffffff815ca143 ffff88080946a800
[ 7676.100627] Call Trace:
[ 7676.100633] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.100662] [<ffffffffa036d299>] wait_log_commit+0xe9/0x110 [btrfs]
[ 7676.100667] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.100697] [<ffffffffa0372d5a>] btrfs_sync_log+0x3ea/0xac0 [btrfs]
[ 7676.100702] [<ffffffff81200701>] ? dput+0xc1/0x240
[ 7676.100731] [<ffffffffa0373a15>] ? btrfs_log_dentry_safe+0x75/0x90 [btrfs]
[ 7676.100759] [<ffffffffa034728e>] btrfs_sync_file+0x2ee/0x350 [btrfs]
[ 7676.100765] [<ffffffff8121ce76>] vfs_fsync_range+0x46/0xc0
[ 7676.100770] [<ffffffff811e75ab>] ? do_sys_open+0x1bb/0x240
[ 7676.100774] [<ffffffff8121cf54>] do_fsync+0x44/0x70
[ 7676.100779] [<ffffffff8121d200>] SyS_fsync+0x10/0x20
[ 7676.100785] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
[ 7676.100790] INFO: task rdiff-backup:17238 blocked for more than 120 seconds.
[ 7676.100801] Not tainted 4.3.3-rm1+ #101
[ 7676.100809] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.100822] rdiff-backup D ffff88082edd5cc0 0 17238 17236 0x00000000
[ 7676.100828] ffff88015a74b8c8 0000000000000082 ffff88080af30000 ffff88015a630000
[ 7676.100834] ffff88015a74c000 ffff88058b93cb58 ffff88058b93cb70 ffff88015a74b908
[ 7676.100839] ffff88058b93cb50 ffff88015a74b8e0 ffffffff815ca143 ffff88058b93caf0
[ 7676.100845] Call Trace:
[ 7676.100850] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.100878] [<ffffffffa036c579>] btrfs_tree_lock+0x79/0x210 [btrfs]
[ 7676.100884] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.100901] [<ffffffffa0304694>] btrfs_lock_root_node+0x34/0x50 [btrfs]
[ 7676.100919] [<ffffffffa0309b76>] btrfs_search_slot+0x8e6/0x9f0 [btrfs]
[ 7676.100938] [<ffffffffa030b738>] btrfs_insert_empty_items+0x78/0xd0 [btrfs]
[ 7676.100965] [<ffffffffa03aa883>] insert_dir_log_key+0x54/0xbd [btrfs]
[ 7676.100992] [<ffffffffa03ac1ee>] log_dir_items+0x49e/0x4c2 [btrfs]
[ 7676.101020] [<ffffffffa03ac27e>] log_directory_changes+0x6c/0xb4 [btrfs]
[ 7676.101048] [<ffffffffa03ace15>] btrfs_log_inode+0xb4f/0xbcf [btrfs]
[ 7676.101054] [<ffffffff81200701>] ? dput+0xc1/0x240
[ 7676.101082] [<ffffffffa0371d59>] btrfs_log_inode_parent+0x2c9/0xee0 [btrfs]
[ 7676.101088] [<ffffffff811f81d3>] ? putname+0x53/0x60
[ 7676.101114] [<ffffffffa032f221>] ? wait_current_trans.isra.21+0x31/0x120 [btrfs]
[ 7676.101120] [<ffffffff811cdd3d>] ? kmem_cache_alloc+0x2d/0x130
[ 7676.101145] [<ffffffffa032ece5>] ? join_transaction.isra.15+0x25/0x440 [btrfs]
[ 7676.101193] [<ffffffffa0373a0a>] btrfs_log_dentry_safe+0x6a/0x90 [btrfs]
[ 7676.101236] [<ffffffffa03471dd>] btrfs_sync_file+0x23d/0x350 [btrfs]
[ 7676.101257] [<ffffffff8121ce76>] vfs_fsync_range+0x46/0xc0
[ 7676.101278] [<ffffffff811e75ab>] ? do_sys_open+0x1bb/0x240
[ 7676.101299] [<ffffffff8121cf54>] do_fsync+0x44/0x70
[ 7676.101320] [<ffffffff8121d200>] SyS_fsync+0x10/0x20
[ 7676.101345] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
[ 7676.101366] INFO: task rdiff-backup:17241 blocked for more than 120 seconds.
[ 7676.101386] Not tainted 4.3.3-rm1+ #101
[ 7676.101405] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 7676.101417] rdiff-backup D ffff88082ec95cc0 0 17241 17239 0x00000000
[ 7676.101423] ffff88046cc8f9b8 0000000000000082 ffff88080aefd7c0 ffff88047ed41d40
[ 7676.101428] ffff88046cc90000 ffff880665f385e0 ffff880665f385f8 ffff88046cc8f9f8
[ 7676.101433] ffff880665f385d8 ffff88046cc8f9d0 ffffffff815ca143 ffff880665f38578
[ 7676.101439] Call Trace:
[ 7676.101444] [<ffffffff815ca143>] schedule+0x33/0x80
[ 7676.101472] [<ffffffffa036c579>] btrfs_tree_lock+0x79/0x210 [btrfs]
[ 7676.101477] [<ffffffff810bc270>] ? wait_woken+0x90/0x90
[ 7676.101496] [<ffffffffa030997e>] btrfs_search_slot+0x6ee/0x9f0 [btrfs]
[ 7676.101518] [<ffffffffa0322764>] btrfs_lookup_xattr+0x84/0xd0 [btrfs]
[ 7676.101547] [<ffffffffa034a53b>] do_setxattr+0x30b/0x440 [btrfs]
[ 7676.101572] [<ffffffffa0330a92>] ? start_transaction+0x92/0x580 [btrfs]
[ 7676.101601] [<ffffffffa034a90f>] __btrfs_setxattr+0x8f/0x100 [btrfs]
[ 7676.101629] [<ffffffffa03a8f57>] __btrfs_set_acl+0xd7/0x180 [btrfs]
[ 7676.101658] [<ffffffffa03a9138>] btrfs_set_acl+0x18/0x20 [btrfs]
[ 7676.101664] [<ffffffff812481e7>] posix_acl_xattr_set+0xf7/0x120
[ 7676.101670] [<ffffffff8120e429>] generic_setxattr+0x69/0x80
[ 7676.101698] [<ffffffffa034adfd>] btrfs_setxattr+0xbd/0xe0 [btrfs]
[ 7676.101704] [<ffffffff8120ef21>] __vfs_setxattr_noperm+0x71/0x1b0
[ 7676.101710] [<ffffffff81286d32>] ? security_inode_setxattr+0x92/0xb0
[ 7676.101714] [<ffffffff8120f109>] vfs_setxattr+0xa9/0xb0
[ 7676.101720] [<ffffffff8120f290>] setxattr+0x180/0x200
[ 7676.101726] [<ffffffff812060bf>] ? notify_change+0x2df/0x360
[ 7676.101730] [<ffffffff811cdd3d>] ? kmem_cache_alloc+0x2d/0x130
[ 7676.101736] [<ffffffff811f8241>] ? getname_flags+0x61/0x210
[ 7676.101742] [<ffffffff810c249d>] ? percpu_down_read+0x1d/0x80
[ 7676.101748] [<ffffffff8120f3ba>] path_setxattr+0xaa/0xe0
[ 7676.101754] [<ffffffff8120f5b4>] SyS_setxattr+0x14/0x20
[ 7676.101760] [<ffffffff815ce3b6>] entry_SYSCALL_64_fastpath+0x16/0x75
--
With respect,
Roman
[-- Attachment #1.2: sysrq_w.txt.bz2 --]
[-- Type: application/x-bzip, Size: 25419 bytes --]
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 181 bytes --]
next prev parent reply other threads:[~2016-01-10 0:31 UTC|newest]
Thread overview: 6+ messages / expand[flat|nested] mbox.gz Atom feed top
2015-12-26 2:00 Deadlock after upgrade to 4.1 Roman Mamedov
2015-12-26 4:04 ` Duncan
2015-12-26 4:34 ` Chris Murphy
2015-12-29 13:24 ` Rich Freeman
2016-01-10 0:31 ` Roman Mamedov [this message]
2016-01-25 15:53 ` Reproduced deadlock after upgrade from 3.18 to 4.1 or 4.3 (+ more info) Roman Mamedov
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20160110053119.45e05246@natsu \
--to=rm@romanrm.net \
--cc=linux-btrfs@vger.kernel.org \
--cc=lists@colorremedies.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).