From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-wm0-f50.google.com ([74.125.82.50]:34674 "EHLO mail-wm0-f50.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S965742AbcBBUUj (ORCPT ); Tue, 2 Feb 2016 15:20:39 -0500 Received: by mail-wm0-f50.google.com with SMTP id 128so135601211wmz.1 for ; Tue, 02 Feb 2016 12:20:38 -0800 (PST) MIME-Version: 1.0 From: =?UTF-8?B?0JzQuNGF0LDQuNC7INCT0LDQstGA0LjQu9C+0LI=?= Date: Wed, 3 Feb 2016 01:20:22 +0500 Message-ID: Subject: task btrfs-cleaner:770 blocked for more than 120 seconds. To: linux-btrfs@vger.kernel.org Content-Type: text/plain; charset=UTF-8 Sender: linux-btrfs-owner@vger.kernel.org List-ID: Hi all! I have problem with hanging btrfs file system. [17047.652816] INFO: task btrfs-cleaner:770 blocked for more than 120 seconds. [17047.652837] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.652853] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.652875] btrfs-cleaner D ffff8807fe3d7a18 10264 770 2 0x00000080 [17047.652880] ffff8807e50f7a50 0000000000000092 ffffffff811067cd ffff880700000000 [17047.652882] ffff8807fa344000 ffff8807e68ec000 ffff8807e50f8000 ffff880003753e90 [17047.652884] ffff8807e68ec000 ffff8807e68ec000 ffff8807e50f7a90 ffff8807e50f7a68 [17047.652886] Call Trace: [17047.652891] [] ? trace_hardirqs_on+0xd/0x10 [17047.652894] [] schedule+0x3a/0x90 [17047.652909] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.652912] [] ? wake_atomic_t_function+0x70/0x70 [17047.652918] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.652923] [] btrfs_search_forward+0x59/0x350 [btrfs] [17047.652927] [] ? kmem_cache_alloc+0x281/0x310 [17047.652931] [] ? btrfs_alloc_path+0x1a/0x20 [btrfs] [17047.652940] [] find_new_extents.constprop.43+0xa6/0x2d0 [btrfs] [17047.652942] [] ? trace_hardirqs_on_caller+0x129/0x1b0 [17047.652943] [] ? trace_hardirqs_on+0xd/0x10 [17047.652952] [] btrfs_defrag_file+0x8d8/0xd60 [btrfs] [17047.652955] [] ? __sb_start_write+0xc9/0x110 [17047.652963] [] btrfs_run_defrag_inodes+0x242/0x390 [btrfs] [17047.652971] [] ? btrfs_run_defrag_inodes+0xf0/0x390 [btrfs] [17047.652978] [] cleaner_kthread+0xcb/0x210 [btrfs] [17047.652984] [] ? btree_read_extent_buffer_pages.constprop.54+0x110/0x110 [btrfs] [17047.652986] [] kthread+0x101/0x120 [17047.652987] [] ? trace_hardirqs_on_caller+0x129/0x1b0 [17047.652989] [] ? kthread_create_on_node+0x250/0x250 [17047.652991] [] ret_from_fork+0x3f/0x70 [17047.652992] [] ? kthread_create_on_node+0x250/0x250 [17047.652993] 1 lock held by btrfs-cleaner/770: [17047.652994] #0: (sb_writers#16){.+.+.+}, at: [] __sb_start_write+0xc9/0x110 [17047.652999] INFO: task btrfs-transacti:771 blocked for more than 120 seconds. [17047.653019] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653032] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653053] btrfs-transacti D ffff8807fe1d7a18 9912 771 2 0x00000080 [17047.653056] ffff8807e50fbb20 0000000000000096 ffffffff811067cd ffff880700000000 [17047.653058] ffff8807fa33c000 ffff8807f7140000 ffff8807e50fc000 ffff880003753e90 [17047.653060] ffff8807f7140000 ffff8807f7140000 ffff8807e50fbb60 ffff8807e50fbb38 [17047.653062] Call Trace: [17047.653063] [] ? trace_hardirqs_on+0xd/0x10 [17047.653065] [] schedule+0x3a/0x90 [17047.653074] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.653076] [] ? wake_atomic_t_function+0x70/0x70 [17047.653081] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.653086] [] btrfs_search_slot+0x73f/0x9f0 [btrfs] [17047.653092] [] btrfs_insert_empty_items+0x71/0xc0 [btrfs] [17047.653101] [] __btrfs_run_delayed_items+0x135/0x600 [btrfs] [17047.653104] [] ? local_clock+0x1c/0x20 [17047.653113] [] btrfs_run_delayed_items+0x13/0x20 [btrfs] [17047.653120] [] btrfs_commit_transaction+0x2f0/0xbd0 [btrfs] [17047.653127] [] transaction_kthread+0x208/0x270 [btrfs] [17047.653134] [] ? btrfs_cleanup_transaction+0x610/0x610 [btrfs] [17047.653135] [] kthread+0x101/0x120 [17047.653137] [] ? trace_hardirqs_on_caller+0x129/0x1b0 [17047.653138] [] ? kthread_create_on_node+0x250/0x250 [17047.653140] [] ret_from_fork+0x3f/0x70 [17047.653141] [] ? kthread_create_on_node+0x250/0x250 [17047.653142] 2 locks held by btrfs-transacti/771: [17047.653143] #0: (&fs_info->transaction_kthread_mutex){+.+...}, at: [] transaction_kthread+0x72/0x270 [btrfs] [17047.653151] #1: (&delayed_node->mutex){+.+.-.}, at: [] __btrfs_run_delayed_items+0xfc/0x600 [btrfs] [17047.653190] INFO: task systemd:2059 blocked for more than 120 seconds. [17047.653209] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653225] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653246] systemd D ffff8807fe5d7a18 12696 2059 1 0x00000000 [17047.653250] ffff8807f6d9f9b8 0000000000000082 ffffffff81f62300 0000000000000004 [17047.653252] ffff880725b84000 ffff8807c0afc000 ffff8807f6da0000 ffff880003753e90 [17047.653253] ffff8807c0afc000 ffff8807c0afc000 ffff8807f6d9f9f8 ffff8807f6d9f9d0 [17047.653255] Call Trace: [17047.653257] [] schedule+0x3a/0x90 [17047.653266] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.653268] [] ? wake_atomic_t_function+0x70/0x70 [17047.653273] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.653278] [] btrfs_search_slot+0x73f/0x9f0 [btrfs] [17047.653286] [] ? btrfs_crc32c+0x68/0x90 [btrfs] [17047.653292] [] btrfs_lookup_dir_item+0x78/0xc0 [btrfs] [17047.653300] [] btrfs_lookup_dentry+0xb6/0x550 [btrfs] [17047.653302] [] ? _raw_spin_unlock+0x27/0x40 [17047.653309] [] btrfs_lookup+0x12/0x40 [btrfs] [17047.653311] [] lookup_real+0x1d/0x60 [17047.653312] [] __lookup_hash+0x42/0x60 [17047.653314] [] walk_component+0x1df/0x2a0 [17047.653315] [] link_path_walk+0x190/0x5a0 [17047.653317] [] ? path_init+0x557/0x800 [17047.653318] [] ? path_init+0x50f/0x800 [17047.653319] [] path_openat+0xab/0x1260 [17047.653321] [] ? sched_clock+0x9/0x10 [17047.653323] [] ? local_clock+0x1c/0x20 [17047.653325] [] do_filp_open+0x91/0x100 [17047.653326] [] ? _raw_spin_unlock+0x27/0x40 [17047.653328] [] ? __alloc_fd+0xaf/0x180 [17047.653330] [] do_sys_open+0x13a/0x230 [17047.653332] [] SyS_open+0x1e/0x20 [17047.653333] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.653335] 1 lock held by systemd/2059: [17047.653335] #0: (&type->i_mutex_dir_key#4){+.+.+.}, at: [] walk_component+0x1d0/0x2a0 [17047.653345] INFO: task gnome-shell:2455 blocked for more than 120 seconds. [17047.653362] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653377] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653398] gnome-shell D ffff8807fe3d7a18 11064 2455 2276 0x00000000 [17047.653401] ffff8807b48cfb70 0000000000000096 ffff8807b5a64928 ffff880700000000 [17047.653403] ffff8807fa344000 ffff8807b5a64000 ffff8807b48d0000 0000000000000246 [17047.653405] ffff8807e5fa0cd0 ffff8807b5a64000 00000000ffffffff ffff8807b48cfb88 [17047.653407] Call Trace: [17047.653408] [] schedule+0x3a/0x90 [17047.653410] [] schedule_preempt_disabled+0x15/0x20 [17047.653412] [] mutex_lock_nested+0x190/0x400 [17047.653413] [] ? walk_component+0x1d0/0x2a0 [17047.653414] [] ? walk_component+0x1d0/0x2a0 [17047.653416] [] walk_component+0x1d0/0x2a0 [17047.653417] [] link_path_walk+0x190/0x5a0 [17047.653419] [] ? path_init+0x557/0x800 [17047.653420] [] ? path_init+0x50f/0x800 [17047.653421] [] path_lookupat+0x7c/0x110 [17047.653422] [] filename_lookup+0xb1/0x180 [17047.653426] [] ? rcu_read_lock_sched_held+0x6d/0x80 [17047.653428] [] ? kmem_cache_alloc+0x281/0x310 [17047.653429] [] ? getname_flags+0x56/0x1f0 [17047.653432] [] ? sched_clock+0x9/0x10 [17047.653433] [] user_path_at_empty+0x36/0x40 [17047.653435] [] vfs_fstatat+0x66/0xc0 [17047.653436] [] SYSC_newstat+0x2e/0x60 [17047.653439] [] ? __do_page_fault+0x1e8/0x470 [17047.653441] [] ? trace_hardirqs_on_caller+0x129/0x1b0 [17047.653443] [] ? lockdep_sys_exit_thunk+0x12/0x14 [17047.653445] [] SyS_newstat+0xe/0x10 [17047.653446] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.653448] 1 lock held by gnome-shell/2455: [17047.653448] #0: (&type->i_mutex_dir_key#4){+.+.+.}, at: [] walk_component+0x1d0/0x2a0 [17047.653471] INFO: task htop:3020 blocked for more than 120 seconds. [17047.653488] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653502] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653523] htop D ffff8807fddd7a18 11800 3020 2972 0x00000000 [17047.653527] ffff88078866bcb8 0000000000000082 ffffffffffffffff ffff880700000000 [17047.653529] ffffffff81e12500 ffff88078b5dc000 ffff88078866c000 ffff8807c0b66eb0 [17047.653530] ffffffffffffffff ffff8807c0b66ec8 ffff8807c0b66e00 ffff88078866bcd0 [17047.653532] Call Trace: [17047.653534] [] schedule+0x3a/0x90 [17047.653536] [] rwsem_down_read_failed+0xcf/0x140 [17047.653539] [] call_rwsem_down_read_failed+0x14/0x30 [17047.653541] [] ? down_read+0x83/0xa0 [17047.653544] [] ? proc_pid_cmdline_read+0xb1/0x560 [17047.653546] [] proc_pid_cmdline_read+0xb1/0x560 [17047.653547] [] ? trace_hardirqs_on_caller+0x129/0x1b0 [17047.653549] [] __vfs_read+0x37/0x100 [17047.653551] [] ? security_file_permission+0xa3/0xc0 [17047.653553] [] vfs_read+0x86/0x130 [17047.653554] [] SyS_read+0x58/0xd0 [17047.653555] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.653557] 1 lock held by htop/3020: [17047.653557] #0: (&mm->mmap_sem){++++++}, at: [] proc_pid_cmdline_read+0xb1/0x560 [17047.653563] INFO: task SQLyog.exe:3780 blocked for more than 120 seconds. [17047.653579] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653595] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653616] SQLyog.exe D ffff8807fe1d7a18 11192 3780 3069 0x00000000 [17047.653619] ffff8807384f7c90 0000000000000092 ffffffff811067cd ffff880700000000 [17047.653621] ffff8807fa33c000 ffff88073854c000 ffff8807384f8000 ffff880003753e90 [17047.653623] ffff88073854c000 ffff88073854c000 ffff8807384f7cd0 ffff8807384f7ca8 [17047.653624] Call Trace: [17047.653626] [] ? trace_hardirqs_on+0xd/0x10 [17047.653628] [] schedule+0x3a/0x90 [17047.653637] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.653639] [] ? wake_atomic_t_function+0x70/0x70 [17047.653644] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.653649] [] btrfs_search_slot+0x73f/0x9f0 [btrfs] [17047.653650] [] ? trace_hardirqs_on+0xd/0x10 [17047.653652] [] ? mutex_unlock+0xe/0x10 [17047.653659] [] btrfs_real_readdir+0xe9/0x590 [btrfs] [17047.653662] [] iterate_dir+0x97/0x130 [17047.653663] [] SyS_getdents+0x9a/0x130 [17047.653664] [] ? fillonedir+0x100/0x100 [17047.653666] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.653667] 1 lock held by SQLyog.exe/3780: [17047.653668] #0: (&type->i_mutex_dir_key#4){+.+.+.}, at: [] iterate_dir+0x61/0x130 [17047.653677] INFO: task chrome:3329 blocked for more than 120 seconds. [17047.653694] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653710] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653728] chrome D ffff8807fe3d7a18 11432 3329 3267 0x00000000 [17047.653732] ffff88076ea27dc8 0000000000000086 ffffffffffffffff ffff880700000000 [17047.653734] ffff8807fa344000 ffff8807706f4000 ffff88076ea28000 ffff8807f4ab00b0 [17047.653735] ffffffffffffffff ffff8807f4ab00c8 ffff8807706f4000 ffff88076ea27de0 [17047.653737] Call Trace: [17047.653739] [] schedule+0x3a/0x90 [17047.653741] [] rwsem_down_read_failed+0xcf/0x140 [17047.653743] [] call_rwsem_down_read_failed+0x14/0x30 [17047.653745] [] ? down_read+0x83/0xa0 [17047.653746] [] ? __do_page_fault+0x3dc/0x470 [17047.653748] [] __do_page_fault+0x3dc/0x470 [17047.653749] [] ? vfs_read+0x117/0x130 [17047.653751] [] do_page_fault+0x2f/0x80 [17047.653753] [] page_fault+0x28/0x30 [17047.653754] 1 lock held by chrome/3329: [17047.653755] #0: (&mm->mmap_sem){++++++}, at: [] __do_page_fault+0x3dc/0x470 [17047.653774] INFO: task BrowserBlocking:3499 blocked for more than 120 seconds. [17047.653792] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.653807] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.653828] BrowserBlocking D ffff8807fddd7a18 10840 3499 3267 0x00000000 [17047.653832] ffff880767137658 0000000000000086 ffffffff811067cd ffff880700000000 [17047.653834] ffffffff81e12500 ffff8807c0ac0000 ffff880767138000 ffff880003753e90 [17047.653835] ffff8807c0ac0000 ffff8807c0ac0000 ffff880767137698 ffff880767137670 [17047.653837] Call Trace: [17047.653839] [] ? trace_hardirqs_on+0xd/0x10 [17047.653841] [] schedule+0x3a/0x90 [17047.653850] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.653851] [] ? wake_atomic_t_function+0x70/0x70 [17047.653856] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.653861] [] btrfs_search_slot+0x73f/0x9f0 [btrfs] [17047.653868] [] btrfs_lookup_file_extent+0x49/0x60 [btrfs] [17047.653876] [] __btrfs_drop_extents+0x185/0xd90 [btrfs] [17047.653878] [] ? debug_lockdep_rcu_enabled+0x1d/0x20 [17047.653885] [] ? start_transaction+0x91/0x610 [btrfs] [17047.653893] [] cow_file_range_inline+0x1b6/0x690 [btrfs] [17047.653901] [] ? __set_extent_bit+0x472/0x570 [btrfs] [17047.653909] [] cow_file_range+0x34e/0x440 [btrfs] [17047.653911] [] ? _raw_spin_unlock+0x27/0x40 [17047.653919] [] ? test_range_bit+0xe5/0x130 [btrfs] [17047.653927] [] run_delalloc_range+0x3bc/0x3f0 [btrfs] [17047.653935] [] ? find_lock_delalloc_range.constprop.42+0x1e7/0x210 [btrfs] [17047.653944] [] writepage_delalloc.isra.34+0x105/0x170 [btrfs] [17047.653952] [] __extent_writepage+0xf5/0x3d0 [btrfs] [17047.653962] [] extent_write_cache_pages.isra.31.constprop.47+0x30a/0x400 [btrfs] [17047.653965] [] ? sched_clock+0x9/0x10 [17047.653967] [] ? local_clock+0x1c/0x20 [17047.653977] [] extent_writepages+0x5c/0x90 [btrfs] [17047.653987] [] ? btrfs_real_readdir+0x590/0x590 [btrfs] [17047.653994] [] btrfs_writepages+0x28/0x30 [btrfs] [17047.653996] [] do_writepages+0x21/0x30 [17047.653998] [] __filemap_fdatawrite_range+0xc6/0x100 [17047.654000] [] filemap_fdatawrite_range+0x13/0x20 [17047.654008] [] btrfs_fdatawrite_range+0x20/0x50 [btrfs] [17047.654016] [] start_ordered_ops+0x19/0x30 [btrfs] [17047.654023] [] btrfs_sync_file+0x83/0x420 [btrfs] [17047.654026] [] vfs_fsync_range+0x4b/0xb0 [17047.654029] [] ? __fget_light+0x2a/0x90 [17047.654031] [] do_fsync+0x3d/0x70 [17047.654032] [] SyS_fdatasync+0x13/0x20 [17047.654034] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.654035] 1 lock held by BrowserBlocking/3499: [17047.654035] #0: (sb_internal#2){.+.+..}, at: [] __sb_start_write+0xc9/0x110 [17047.654040] INFO: task BrowserBlocking:3500 blocked for more than 120 seconds. [17047.654057] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.654071] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.654089] BrowserBlocking D ffff8807fe9d7a18 10840 3500 3267 0x00000000 [17047.654092] ffff88074fc03ac8 0000000000000086 ffffffff811067cd ffff880700000000 [17047.654094] ffff8807fa364000 ffff880767f40000 ffff88074fc04000 ffff880003753e90 [17047.654096] ffff880767f40000 ffff880767f40000 ffff88074fc03b08 ffff88074fc03ae0 [17047.654097] Call Trace: [17047.654099] [] ? trace_hardirqs_on+0xd/0x10 [17047.654101] [] schedule+0x3a/0x90 [17047.654108] [] btrfs_tree_read_lock+0x102/0x160 [btrfs] [17047.654109] [] ? wake_atomic_t_function+0x70/0x70 [17047.654113] [] btrfs_read_lock_root_node+0x34/0x50 [btrfs] [17047.654117] [] btrfs_search_slot+0x73f/0x9f0 [btrfs] [17047.654123] [] btrfs_lookup_inode+0x3e/0xc0 [btrfs] [17047.654129] [] btrfs_iget+0xf9/0x6a0 [btrfs] [17047.654133] [] ? btrfs_search_forward+0x2d9/0x350 [btrfs] [17047.654140] [] btrfs_log_inode_parent+0xbc4/0xeb0 [btrfs] [17047.654147] [] btrfs_log_dentry_safe+0x62/0x80 [btrfs] [17047.654153] [] btrfs_sync_file+0x2fe/0x420 [btrfs] [17047.654154] [] vfs_fsync_range+0x4b/0xb0 [17047.654155] [] ? __fget_light+0x2a/0x90 [17047.654156] [] do_fsync+0x3d/0x70 [17047.654157] [] SyS_fdatasync+0x13/0x20 [17047.654158] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.654160] 2 locks held by BrowserBlocking/3500: [17047.654160] #0: (&type->i_mutex_dir_key#4){+.+.+.}, at: [] btrfs_sync_file+0x14f/0x420 [btrfs] [17047.654167] #1: (sb_internal#2){.+.+..}, at: [] __sb_start_write+0xc9/0x110 [17047.654170] INFO: task Chrome_DBThread:3501 blocked for more than 120 seconds. [17047.654187] Not tainted 4.3.5-300.fc23.x86_64+debug #1 [17047.654201] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [17047.654218] Chrome_DBThread D ffff8807fe3d7a18 10536 3501 3267 0x00000000 [17047.654221] ffff880759bf3cf0 0000000000000092 ffffffff811067cd ffff880700000000 [17047.654222] ffff8807fa344000 ffff880767f68000 ffff880759bf4000 ffff880037c60800 [17047.654224] 0000000000000001 0000000000000000 ffff880037c60780 ffff880759bf3d08 [17047.654226] Call Trace: [17047.654227] [] ? trace_hardirqs_on+0xd/0x10 [17047.654228] [] schedule+0x3a/0x90 [17047.654235] [] btrfs_start_ordered_extent+0x164/0x1f0 [btrfs] [17047.654237] [] ? wake_atomic_t_function+0x70/0x70 [17047.654245] [] btrfs_wait_ordered_range+0xa9/0x110 [btrfs] [17047.654252] [] btrfs_truncate+0x43/0x2c0 [btrfs] [17047.654260] [] btrfs_setattr+0x1f4/0x370 [btrfs] [17047.654261] [] notify_change+0x245/0x360 [17047.654264] [] do_truncate+0x77/0xc0 [17047.654266] [] do_sys_ftruncate.constprop.13+0x112/0x160 [17047.654267] [] SyS_ftruncate+0xe/0x10 [17047.654269] [] entry_SYSCALL_64_fastpath+0x12/0x76 [17047.654270] 2 locks held by Chrome_DBThread/3501: [17047.654271] #0: (sb_writers#16){.+.+.+}, at: [] __sb_start_write+0xc9/0x110 [17047.654274] #1: (&sb->s_type->i_mutex_key#19){+.+.+.}, at: [] do_truncate+0x69/0xc0 -- Best Regards, Mike Gavrilov.