Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753820AbcDASMo (ORCPT ); Fri, 1 Apr 2016 14:12:44 -0400 Received: from arcturus.aphlor.org ([188.246.204.175]:60534 "EHLO arcturus.aphlor.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751318AbcDASMl (ORCPT ); Fri, 1 Apr 2016 14:12:41 -0400 Date: Fri, 1 Apr 2016 14:12:27 -0400 From: Dave Jones To: Linux Kernel , Chris Mason , Josef Bacik , David Sterba , linux-btrfs@vger.kernel.org Subject: Re: btrfs_destroy_inode WARN_ON. Message-ID: <20160401181227.GA31426@codemonkey.org.uk> Mail-Followup-To: Dave Jones , Linux Kernel , Chris Mason , Josef Bacik , David Sterba , linux-btrfs@vger.kernel.org References: <20160324225411.GA1612@codemonkey.org.uk> <20160328011400.GA19000@codemonkey.org.uk> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20160328011400.GA19000@codemonkey.org.uk> User-Agent: Mutt/1.5.24 (2015-08-30) X-Spam-Score: -2.9 (--) X-Spam-Report: Spam detection software, running on the system "arcturus.aphlor.org", has NOT identified this incoming email as spam. The original message has been attached to this so you can view it or label similar future email. If you have any questions, see the administrator of that system for details. Content preview: On Sun, Mar 27, 2016 at 09:14:00PM -0400, Dave Jones wrote: > > WARNING: CPU: 2 PID: 32570 at fs/btrfs/inode.c:9261 btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > CPU: 2 PID: 32570 Comm: rm Not tainted 4.5.0-think+ #14 > > ffffffffc039baf9 00000000ef721ef0 ffff88025966fc08 ffffffff8957bcdb > > 0000000000000000 0000000000000000 ffff88025966fc50 ffffffff890b41f1 > > ffff88045d918040 0000242d4eed6048 ffff88024eed6048 ffff88024eed6048 > > Call Trace: > > [] ? btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > [] dump_stack+0x68/0x9d > > [] __warn+0x111/0x130 > > [] warn_slowpath_null+0x1d/0x20 > > [] btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > [] destroy_inode+0x67/0x90 > > [] evict+0x1b7/0x240 > > [] iput+0x3ae/0x4e0 > > [] ? dput+0x20e/0x460 > > [] do_unlinkat+0x256/0x440 > > [] ? do_rmdir+0x350/0x350 > > [] ? syscall_trace_enter_phase1+0x87/0x260 > > [] ? enter_from_user_mode+0x50/0x50 > > [] ? __lock_is_held+0x25/0xd0 > > [] ? mark_held_locks+0x22/0xc0 > > [] ? syscall_trace_enter_phase2+0x12d/0x3d0 > > [] ? SyS_rmdir+0x20/0x20 > > [] SyS_unlinkat+0x1b/0x30 > > [] do_syscall_64+0xf4/0x240 > > [] entry_SYSCALL64_slow_path+0x25/0x25 > > ---[ end trace a48ce4e6a1b5e409 ]--- > > > > That's WARN_ON(BTRFS_I(inode)->csum_bytes); > > > > *maybe* it's a bad disk, but there's no indication in dmesg of anything awry. > > Spinning rust on SATA, nothing special. > > Same WARN_ON is reachable from umount too.. > > WARNING: CPU: 2 PID: 20092 at fs/btrfs/inode.c:9261 btrfs_destroy_inode+0x40c/0x480 [btrfs] > CPU: 2 PID: 20092 Comm: umount Tainted: G W 4.5.0-think+ #1 > 00000000ffffffff 00000000a32c482b ffff8803cd187b60 ffffffff9d63af84 > 0000000000000000 0000000000000000 ffffffffc05c5e40 ffffffffc04d316c > ffff8803cd187ba8 ffffffff9d0c4c27 [...] Content analysis details: (-2.9 points, 5.0 required) pts rule name description ---- ---------------------- -------------------------------------------------- -1.0 ALL_TRUSTED Passed through trusted hosts only via SMTP -1.9 BAYES_00 BODY: Bayes spam probability is 0 to 1% [score: 0.0000] Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 8720 Lines: 163 On Sun, Mar 27, 2016 at 09:14:00PM -0400, Dave Jones wrote: > > WARNING: CPU: 2 PID: 32570 at fs/btrfs/inode.c:9261 btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > CPU: 2 PID: 32570 Comm: rm Not tainted 4.5.0-think+ #14 > > ffffffffc039baf9 00000000ef721ef0 ffff88025966fc08 ffffffff8957bcdb > > 0000000000000000 0000000000000000 ffff88025966fc50 ffffffff890b41f1 > > ffff88045d918040 0000242d4eed6048 ffff88024eed6048 ffff88024eed6048 > > Call Trace: > > [] ? btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > [] dump_stack+0x68/0x9d > > [] __warn+0x111/0x130 > > [] warn_slowpath_null+0x1d/0x20 > > [] btrfs_destroy_inode+0x389/0x3f0 [btrfs] > > [] destroy_inode+0x67/0x90 > > [] evict+0x1b7/0x240 > > [] iput+0x3ae/0x4e0 > > [] ? dput+0x20e/0x460 > > [] do_unlinkat+0x256/0x440 > > [] ? do_rmdir+0x350/0x350 > > [] ? syscall_trace_enter_phase1+0x87/0x260 > > [] ? enter_from_user_mode+0x50/0x50 > > [] ? __lock_is_held+0x25/0xd0 > > [] ? mark_held_locks+0x22/0xc0 > > [] ? syscall_trace_enter_phase2+0x12d/0x3d0 > > [] ? SyS_rmdir+0x20/0x20 > > [] SyS_unlinkat+0x1b/0x30 > > [] do_syscall_64+0xf4/0x240 > > [] entry_SYSCALL64_slow_path+0x25/0x25 > > ---[ end trace a48ce4e6a1b5e409 ]--- > > > > That's WARN_ON(BTRFS_I(inode)->csum_bytes); > > > > *maybe* it's a bad disk, but there's no indication in dmesg of anything awry. > > Spinning rust on SATA, nothing special. > > Same WARN_ON is reachable from umount too.. > > WARNING: CPU: 2 PID: 20092 at fs/btrfs/inode.c:9261 btrfs_destroy_inode+0x40c/0x480 [btrfs] > CPU: 2 PID: 20092 Comm: umount Tainted: G W 4.5.0-think+ #1 > 00000000ffffffff 00000000a32c482b ffff8803cd187b60 ffffffff9d63af84 > 0000000000000000 0000000000000000 ffffffffc05c5e40 ffffffffc04d316c > ffff8803cd187ba8 ffffffff9d0c4c27 ffff880460d80040 0000242dcd187bb0 > Call Trace: > [] dump_stack+0x95/0xe1 > [] ? btrfs_destroy_inode+0x40c/0x480 [btrfs] > [] __warn+0x147/0x170 > [] warn_slowpath_null+0x31/0x40 > [] btrfs_destroy_inode+0x40c/0x480 [btrfs] > [] ? btrfs_test_destroy_inode+0x40/0x40 [btrfs] > [] destroy_inode+0x77/0xb0 > [] evict+0x20e/0x2c0 > [] dispose_list+0x70/0xb0 > [] evict_inodes+0x26f/0x2c0 > [] ? inode_add_lru+0x60/0x60 > [] ? fsnotify_unmount_inodes+0x215/0x2c0 > [] generic_shutdown_super+0x76/0x1c0 > [] kill_anon_super+0x29/0x40 > [] btrfs_kill_super+0x31/0x130 [btrfs] > [] deactivate_locked_super+0x6f/0xb0 > [] deactivate_super+0x99/0xb0 > [] cleanup_mnt+0x70/0xd0 > [] __cleanup_mnt+0x1b/0x20 > [] task_work_run+0xef/0x130 > [] exit_to_usermode_loop+0xf9/0x100 > [] do_syscall_64+0x238/0x2b0 > [] entry_SYSCALL64_slow_path+0x25/0x25 Additional fallout: BTRFS: assertion failed: num_extents, file: fs/btrfs/extent-tree.c, line: 5584 ------------[ cut here ]------------ kernel BUG at fs/btrfs/ctree.h:4320! invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC KASAN CPU: 1 PID: 18815 Comm: trinity-c13 Tainted: G W 4.6.0-rc1-think+ #1 task: ffff88045de10040 ti: ffff8803afa38000 task.ti: ffff8803afa38000 RIP: 0010:[] [] assfail.constprop.88+0x2b/0x2d [btrfs] RSP: 0018:ffff8803afa3f838 EFLAGS: 00010282 RAX: 000000000000004e RBX: ffffffffc046e200 RCX: 0000000000000000 RDX: 0000000000000000 RSI: 0000000000000003 RDI: ffffed0075f47efb RBP: ffff8803afa3f848 R08: 0000000000000001 R09: 0000000000000001 R10: 0000000000000000 R11: 0000000000000001 R12: 00000000000015d0 R13: ffff8803fda0e048 R14: ffff8803fda0dc38 R15: ffff8803fda0dc58 FS: 00007fa0566d6700(0000) GS:ffff880468a00000(0000) knlGS:0000000000000000 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 CR2: 00007fa0566d9000 CR3: 0000000333bc4000 CR4: 00000000001406e0 DR0: 00007fa0554fb000 DR1: 0000000000000000 DR2: 0000000000000000 DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600 Stack: 0000000000000000 ffff8803fda0e048 ffff8803afa3f880 ffffffffc032288b 0000000000000000 ffff880460bb33f8 ffff8803fda0e048 ffff8803fda0dc38 ffff8803fda0dc58 ffff8803afa3f8c8 ffffffffc032f851 0000000000000001 Call Trace: [] drop_outstanding_extent+0x10b/0x130 [btrfs] [] btrfs_delalloc_release_metadata+0x71/0x480 [btrfs] [] ? __btrfs_buffered_write+0xa6f/0xb50 [btrfs] [] btrfs_delalloc_release_space+0x27/0x50 [btrfs] [] __btrfs_buffered_write+0xa28/0xb50 [btrfs] [] ? btrfs_dirty_pages+0x1c0/0x1c0 [btrfs] [] ? filemap_fdatawait_range+0x3e/0x50 [] ? generic_file_direct_write+0x237/0x2f0 [] ? filemap_write_and_wait_range+0xa0/0xa0 [] ? btrfs_file_write_iter+0x670/0x9a0 [btrfs] [] btrfs_file_write_iter+0x74d/0x9a0 [btrfs] [] do_iter_readv_writev+0x153/0x1f0 [] ? btrfs_sync_file+0x920/0x920 [btrfs] [] ? vfs_iter_read+0x1e0/0x1e0 [] ? preempt_count_sub+0xb9/0x130 [] ? percpu_down_read+0x57/0xa0 [] ? __sb_start_write+0xee/0x130 [] ? btrfs_sync_file+0x920/0x920 [btrfs] [] do_readv_writev+0x30f/0x460 [] ? vfs_write+0x2b0/0x2b0 [] ? debug_check_no_locks_freed+0x1b0/0x1b0 [] ? trace_preempt_off+0x3d/0x1c0 [] ? lock_release+0x547/0x8f0 [] ? check_preemption_disabled+0x3b/0x160 [] ? trace_preempt_on+0x3d/0x1a0 [] ? preempt_count_sub+0xb9/0x130 [] ? __context_tracking_exit.part.5+0x9b/0x2b0 [] ? syscall_trace_enter_phase1+0xbc/0x2a0 [] vfs_writev+0x78/0xa0 [] do_pwritev+0x117/0x140 [] ? SyS_preadv2+0x80/0x80 [] SyS_pwritev+0x35/0x40 [] do_syscall_64+0x103/0x2b0 [] entry_SYSCALL64_slow_path+0x25/0x25 Code: 55 48 89 e5 41 54 41 89 f4 53 48 89 fb e8 e6 95 da d7 44 89 e1 48 89 de 48 c7 c2 60 de 46 c0 48 c7 c7 a0 e1 46 c0 e8 fc d5 e5 d7 <0f> 0b 55 48 89 e5 41 57 45 89 c7 41 56 49 89 ce 41 55 49 89 d5 RIP [] assfail.constprop.88+0x2b/0x2d [btrfs] RSP ---[ end trace 40e67d85fcda7cb2 ]--- BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 30s! Showing busy workqueues and worker pools: workqueue events: flags=0x0 pwq 6: cpus=3 node=0 flags=0x0 nice=0 active=1/256 pending: vmstat_shepherd pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256 pending: check_corruption pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=3/256 pending: usb_serial_port_work, lru_add_drain_per_cpu BAR(17230), e1000_watchdog_task workqueue events_power_efficient: flags=0x82 pwq 8: cpus=0-3 flags=0x4 nice=0 active=3/256 pending: fb_flashcursor, neigh_periodic_work, neigh_periodic_work workqueue events_freezable_power_: flags=0x86 pwq 8: cpus=0-3 flags=0x4 nice=0 active=1/256 pending: disk_events_workfn workqueue netns: flags=0x6000a pwq 8: cpus=0-3 flags=0x4 nice=0 active=1/1 in-flight: 10038:cleanup_net workqueue writeback: flags=0x4e pwq 8: cpus=0-3 flags=0x4 nice=0 active=2/256 pending: wb_workfn, wb_workfn workqueue kblockd: flags=0x18 pwq 3: cpus=1 node=0 flags=0x0 nice=-20 active=2/256 pending: blk_mq_timeout_work, blk_mq_timeout_work workqueue vmstat: flags=0xc pwq 4: cpus=2 node=0 flags=0x0 nice=0 active=1/256 pending: vmstat_update pwq 2: cpus=1 node=0 flags=0x0 nice=0 active=1/256 pending: vmstat_update pwq 0: cpus=0 node=0 flags=0x0 nice=0 active=1/256 pending: vmstat_update pool 8: cpus=0-3 flags=0x4 nice=0 hung=0s workers=11 idle: 11638 10276 609 17937 606 9237 605 891 15998 14100 note: trinity-c13[18815] exited with preempt_count 1