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 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.