Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753764AbaJQSqy (ORCPT ); Fri, 17 Oct 2014 14:46:54 -0400 Received: from homie.mail.dreamhost.com ([208.97.132.208]:59053 "EHLO homiemail-a14.g.dreamhost.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753313AbaJQSqv convert rfc822-to-8bit (ORCPT ); Fri, 17 Oct 2014 14:46:51 -0400 Message-ID: <1413571596.20178.3.camel@linux-t7sj.site> Subject: Re: btrfs soft lockups: locks gone crazy From: Davidlohr Bueso To: LKML Cc: linux-btrfs@vger.kernel.org, Josef Bacik Date: Fri, 17 Oct 2014 11:46:36 -0700 In-Reply-To: <1413271664.27233.13.camel@linux-t7sj.site> References: <1413271664.27233.13.camel@linux-t7sj.site> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.10.4 Mime-Version: 1.0 Content-Transfer-Encoding: 8BIT Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org ping? On Tue, 2014-10-14 at 00:27 -0700, Davidlohr Bueso wrote: > Hello, > > I'm getting massive amounts of cpu soft lockups in Linus's tree for > today. This occurs almost immediately and is very reproducible in aim7 > disk workloads using btrfs: > > kernel:[ 559.800017] NMI watchdog: BUG: soft lockup - CPU#114 stuck for 22s! [reaim:44435] > ... > [ 999.800070] Modules linked in: iptable_filter(E) ip_tables(E) x_tables(E) rpcsec_gss_krb5(E) auth_rpcgss(E) nfsv4(E) dns_resolver(E) nfs(E) lockd(E) grace(E) sunrpc(E) fscache(E) iscsi_ibft(E) iscsi_boot_sysfs(E) af_packet(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) ext4(E) crc16(E) mbcache(E) coretemp(E) jbd2(E) kvm_intel(E) kvm(E) crct10dif_pclmul(E) crc32_pclmul(E) iTCO_wdt(E) sb_edac(E) iTCO_vendor_support(E) joydev(E) ghash_clmulni_intel(E) aesni_intel(E) aes_x86_64(E) lrw(E) gf128mul(E) glue_helper(E) ablk_helper(E) cryptd(E) pcspkr(E) edac_core(E) i2c_i801(E) lpc_ich(E) mfd_core(E) ipmi_si(E) ipmi_msghandler(E) wmi(E) processor(E) shpchp(E) acpi_pad(E) button(E) dm_mod(E) btrfs(E) xor(E) raid6_pq(E) sd_mod(E) hid_generic(E) usbhid(E) sr_mod(E) cdrom(E) mgag200(E) syscopyarea(E) sysfillrect(E) ehci_pci(E) sysimgblt(E) i2c_algo_bit(E) drm_kms_helper(E) ixgbe(E) ahci(E) ehci_hcd(E) ttm(E) mdio(E) libahci(E) ptp(E) crc32c_intel(E) mpt2sas(E) pps_core(E) usbcore(E) drm(E) libata(E) raid_class(E) usb_common(E) dca(E) scsi_transport_sas(E) sg(E) scsi_mod(E) autofs4(E) > [ 999.800070] CPU: 53 PID: 1027 Comm: kworker/u292:3 Tainted: G EL 3.17.0-3-default+ #2 > [ 999.800070] Hardware name: Intel Corporation BRICKLAND/BRICKLAND, BIOS BIVTSDP1.86B.0044.R01.1310221705 10/22/2013 > [ 999.800070] Workqueue: btrfs-endio-write btrfs_endio_write_helper [btrfs] > [ 999.800070] task: ffff882054e76190 ti: ffff882054e78000 task.ti: ffff882054e78000 > [ 999.800070] RIP: 0010:[] [] queue_read_lock_slowpath+0x86/0x90 > [ 999.800070] RSP: 0018:ffff882054e7ba00 EFLAGS: 00000216 > [ 999.800070] RAX: 0000000000008a64 RBX: ffff882054e7b9b0 RCX: 0000000000008a70 > [ 999.800070] RDX: 0000000000008a70 RSI: 00000000000000c0 RDI: ffff881833b49ea0 > [ 999.800070] RBP: ffff882054e7ba00 R08: ffff881833b49e64 R09: 0000000000000001 > [ 999.800070] R10: 0000000000000000 R11: 00000000ffffffff R12: ffff881047377f00 > [ 999.800070] R13: 0000000000000007 R14: ffff88203bf6d520 R15: ffff881000000000 > [ 999.800070] FS: 0000000000000000(0000) GS:ffff88207f500000(0000) knlGS:0000000000000000 > [ 999.800070] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 999.800070] CR2: 00000000006a7f80 CR3: 0000000001a14000 CR4: 00000000001407e0 > [ 999.800070] Stack: > [ 999.800070] ffff882054e7ba10 ffffffff81573cfc ffff882054e7ba70 ffffffffa033349b > [ 999.800070] ffff882038e9ac80 ffff88203b58fd00 ffff882038cd4ed8 0000000000000000 > [ 999.800070] ffff882054e7ba68 ffff881833b49e30 ffff882057fb4800 0000000000000001 > [ 999.800070] Call Trace: > [ 999.800070] [] _raw_read_lock+0x1c/0x30 > [ 999.800070] [] btrfs_tree_read_lock+0x5b/0x120 [btrfs] > [ 999.800070] [] btrfs_read_lock_root_node+0x3b/0x50 [btrfs] > [ 999.800070] [] btrfs_search_slot+0x53a/0xab0 [btrfs] > [ 999.800070] [] ? cpumask_next_and+0x37/0x50 > [ 999.800070] [] btrfs_lookup_file_extent+0x37/0x40 [btrfs] > [ 999.800070] [] __btrfs_drop_extents+0x16a/0xdb0 [btrfs] > [ 999.800070] [] ? __set_extent_bit+0x22c/0x550 [btrfs] > [ 999.800070] [] ? btrfs_alloc_path+0x1a/0x20 [btrfs] > [ 999.800070] [] insert_reserved_file_extent.constprop.58+0x9e/0x2f0 [btrfs] > [ 999.800070] [] btrfs_finish_ordered_io+0x2e5/0x600 [btrfs] > ... > > [ 1011.800059] CPU: 2 PID: 1 Comm: systemd Tainted: G EL 3.17.0-3-default+ #2 > [ 1011.800059] Hardware name: Intel Corporation BRICKLAND/BRICKLAND, BIOS BIVTSDP1.86B.0044.R01.1310221705 10/22/2013 > [ 1011.800059] task: ffff880857eb8010 ti: ffff880857ebc000 task.ti: ffff880857ebc000 > [ 1011.800059] RIP: 0010:[] [] queue_read_lock_slowpath+0x86/0x90 > [ 1011.800059] RSP: 0018:ffff880857ebfce0 EFLAGS: 00000202 > [ 1011.800059] RAX: 0000000000008a64 RBX: ffff8808549cd910 RCX: 0000000000008a74 > [ 1011.800059] RDX: 0000000000008a74 RSI: 00000000000000c4 RDI: ffff881833b49ea0 > [ 1011.800059] RBP: ffff880857ebfce0 R08: ffff881833b49e64 R09: 0000000000000000 > [ 1011.800059] R10: ffffe8e7ffc4ed60 R11: 0000000000000000 R12: ffff8808549cd900 > [ 1011.800059] R13: 0000000000000000 R14: 0000000000000000 R15: ffff880855e931e0 > [ 1011.800059] FS: 00007f12cb6ec880(0000) GS:ffff88087f840000(0000) knlGS:0000000000000000 > [ 1011.800059] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 1011.800059] CR2: 00007f12cb707000 CR3: 0000002054f16000 CR4: 00000000001407e0 > [ 1011.800059] Stack: > [ 1011.800059] ffff880857ebfcf0 ffffffff81573cfc ffff880857ebfd50 ffffffffa033349b > [ 1011.800059] ffff880857ebfda8 ffffffff811cf72e ffff880857ebfd20 ffffffff811cbef8 > [ 1011.800059] ffff880857ebfda8 ffff881833b49e30 ffff882057fb4800 0000000000000000 > [ 1011.800059] Call Trace: > [ 1011.800059] [] _raw_read_lock+0x1c/0x30 > [ 1011.800059] [] btrfs_tree_read_lock+0x5b/0x120 [btrfs] > [ 1011.800059] [] ? do_last+0x18e/0x11d0 > [ 1011.800059] [] ? inode_permission+0x18/0x50 > [ 1011.800059] [] btrfs_read_lock_root_node+0x3b/0x50 [btrfs] > [ 1011.800059] [] btrfs_search_slot+0x53a/0xab0 [btrfs] > [ 1011.800059] [] ? kmem_cache_alloc+0x47e/0x490 > [ 1011.800059] [] btrfs_real_readdir+0xda/0x570 [btrfs] > [ 1011.800059] [] iterate_dir+0xa3/0x130 > [ 1011.800059] [] SyS_getdents+0x89/0x100 > [ 1011.800059] [] ? fillonedir+0xd0/0xd0 > [ 1011.800059] [] system_call_fastpath+0x16/0x1b > [ 1011.800059] Code: 07 3c ff 74 f8 66 83 47 04 01 5d c3 8b 07 3c ff 75 f8 f3 90 8b 07 3c ff 74 f8 5d c3 0f b7 47 04 66 39 c2 74 b5 f3 90 0f b7 47 04 <66> 39 c1 75 f5 eb a8 0f 1f 00 0f 1f 44 00 00 48 63 ff 55 48 8b > 3c ff 74 f8 5d c3 0f b7 47 04 66 39 c2 74 b5 f3 90 0f b7 47 04 <66> 39 c1 75 f5 eb a8 0f 1f 00 0f 1f 44 00 00 48 63 ff 55 48 8b > > The closes report I've been able to found was from Fengguang: > https://lkml.org/lkml/2014/10/3/183 > However it seems that the 'fix' (commit ea4ebde02e08) does not work in > this case. Are there any particular semantics btrfs relies on for rw > spinlocks that could of been broken with qrwlocks? > > This issue is seen as far as 3.15 (3.14 is ok), however while bisecting > I ran into other, at first glance similar issues, also related to > locking in btrfs. This one actually prevents the whole system from > booting. > > [ 52.294136] ------------[ cut here ]------------ > [ 52.298112] kernel BUG at fs/btrfs/locking.c:269! > [ 52.298112] invalid opcode: 0000 [#1] SMP > [ 52.298112] Modules linked in: acpi_cpufreq(E-) x86_pkg_temp_thermal(E) intel_powerclamp(E) coretemp(E) kvm_intel(E) kvm(E) crct10dif_pclmul(E) crc32_pclmul(E) ghash_clmulni_intel(E) aesni_intel(E) aes_x86_64(E) lrw(E) gf128mul(E) glue_helper(E) pcspkr(E) joydev(E) sb_edac(E) ablk_helper(E) edac_core(E) cryptd(E) i2c_i801(E) lpc_ich(E) mfd_core(E) ipmi_si(E) ipmi_msghandler(E) wmi(E) shpchp(E) button(E) acpi_pad(E) processor(E) dm_mod(E) btrfs(E) xor(E) raid6_pq(E) sd_mod(E) hid_generic(E) usbhid(E) sr_mod(E) cdrom(E) mgag200(E) syscopyarea(E) ixgbe(E) sysfillrect(E) sysimgblt(E) i2c_algo_bit(E) ehci_pci(E) drm_kms_helper(E) mdio(E) ahci(E) ehci_hcd(E) libahci(E) ptp(E) ttm(E) mpt2sas(E) crc32c_intel(E) raid_class(E) pps_core(E) libata(E) drm(E) usbcore(E) usb_common(E) dca(E) scsi_transport_sas(E) sg(E) scsi_mod(E) autofs4(E) > [ 52.298112] CPU: 70 PID: 1304 Comm: systemd-readahe Tainted: G E 3.15.0-3-default #8 > [ 52.298112] Hardware name: Intel Corporation BRICKLAND/BRICKLAND, BIOS BIVTSDP1.86B.0044.R01.1310221705 10/22/2013 > [ 52.298112] task: ffff881052f78010 ti: ffff881055964000 task.ti: ffff881055964000 > [ 52.298112] RIP: 0010:[] [] btrfs_assert_tree_read_locked.part.0+0x9/0xb [btrfs] > [ 52.298112] RSP: 0018:ffff881055967948 EFLAGS: 00010246 > [ 52.298112] RAX: 0000000000000000 RBX: ffff880852806e10 RCX: 0000000000000004 > [ 52.298112] RDX: 0000000000000000 RSI: ffff88085285b270 RDI: ffff880852806e10 > [ 52.298112] RBP: ffff881055967948 R08: 0000000000000000 R09: 000000002d748000 > [ 52.298112] R10: 00000000000003ff R11: 0000000000000001 R12: 0000000000001e1b > [ 52.298112] R13: ffff88087f272c00 R14: 0000000000000001 R15: ffff88085605a000 > [ 52.298112] FS: 00007f33834d2740(0000) GS:ffff88087fb20000(0000) knlGS:0000000000000000 > [ 52.298112] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 52.298112] CR2: 00007f50589787b0 CR3: 00000008553c2000 CR4: 00000000001407e0 > [ 52.298112] Stack: > [ 52.298112] ffff881055967960 ffffffffa02cd8a9 ffff880852806e10 ffff881055967998 > [ 52.298112] ffffffffa028daf6 0000000000000000 0000000000000000 0000000000000000 > [ 52.298112] 0000000000000000 ffff880852806e10 ffff8810559679e8 ffffffffa028eaac > [ 52.298112] Call Trace: > [ 52.298112] [] btrfs_tree_read_unlock_blocking+0xc9/0xd0 [btrfs] > [ 52.298112] [] verify_parent_transid+0x146/0x1f0 [btrfs] > [ 52.298112] [] btree_read_extent_buffer_pages.constprop.52+0xcc/0x120 [btrfs] > [ 52.298112] [] read_tree_block+0x38/0x60 [btrfs] > [ 52.298112] [] btrfs_read_tree_root+0x126/0x190 [btrfs] > [ 52.298112] [] btrfs_read_fs_root+0x12/0x50 [btrfs] > [ 52.298112] [] ? radix_tree_lookup+0xd/0x10 > [ 52.298112] [] btrfs_get_fs_root+0x8d/0x240 [btrfs] > [ 52.298112] [] __resolve_indirect_refs+0xf7/0x6f0 [btrfs] > [ 52.298112] [] ? btrfs_tree_read_lock+0x4c/0xf0 [btrfs] > [ 52.298112] [] ? __add_missing_keys.isra.14+0x76/0x150 [btrfs] > [ 52.298112] [] find_parent_nodes+0x3c0/0x740 [btrfs] > [ 52.298112] [] __btrfs_find_all_roots+0x9a/0x100 [btrfs] > [ 52.298112] [] ? set_state_bits+0x80/0x80 [btrfs] > [ 52.298112] [] iterate_extent_inodes+0x12d/0x310 [btrfs] > [ 52.298112] [] ? set_state_bits+0x80/0x80 [btrfs] > [ 52.298112] [] iterate_inodes_from_logical+0x87/0xa0 [btrfs] > [ 52.298112] [] extent_fiemap+0x262/0x580 [btrfs] > [ 52.298112] [] ? btrfs_get_extent+0xaf0/0xaf0 [btrfs] > [ 52.298112] [] btrfs_fiemap+0x45/0x50 [btrfs] > [ 52.298112] [] do_vfs_ioctl+0x153/0x4b0 > [ 52.298112] [] ? dput+0xb4/0x170 > [ 52.298112] [] SyS_ioctl+0x81/0xa0 > [ 52.298112] [] system_call_fastpath+0x16/0x1b > [ 52.298112] Code: bd d9 ff ff ff 48 89 df e8 91 7f f6 ff 44 89 e8 eb 05 b8 f4 ff ff ff 48 83 c4 30 5b 41 5c 41 5d 5d c3 0f 1f 44 00 00 55 48 89 e5 <0f> 0b 0f 1f 44 00 00 55 48 89 e5 0f 0b 55 be 7f 05 00 00 48 c7 > [ 52.298112] RIP [] btrfs_assert_tree_read_locked.part.0+0x9/0xb [btrfs] > [ 52.298112] RSP > [ 53.230969] ---[ end trace 42ee398737c77c00 ]--- > > The apparent culprit is: > > commit a26e8c9f75b0bfd8cccc9e8f110737b136eb5994 > Author: Josef Bacik > Date: Fri Mar 28 17:07:27 2014 -0400 > > Btrfs: don't clear uptodate if the eb is under IO > > But I cannot say if this is in fact related to the issue I see in newer kernels. > > Ring any bells? > > Thanks, > Davidlohr -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/