Bug 196949 - Frequent btrfs call traces at fs/btrfs/ctree.h:1559
Summary: Frequent btrfs call traces at fs/btrfs/ctree.h:1559
Status: NEW
Alias: None
Product: File System
Classification: Unclassified
Component: btrfs (show other bugs)
Hardware: x86-64 Linux
: P1 low
Assignee: Josef Bacik
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-09-15 18:04 UTC by rrauenza
Modified: 2017-11-04 10:26 UTC (History)
3 users (show)

See Also:
Kernel Version: 4.13.2-1
Tree: Mainline
Regression: No


Attachments

Description rrauenza 2017-09-15 18:04:11 UTC
I get these frequently -- here's the untainted first one:


[    4.747356] ------------[ cut here ]------------
[    4.747377] WARNING: CPU: 3 PID: 439 at fs/btrfs/ctree.h:1559 btrfs_update_device+0x1c5/0x1d0 [btrfs]
[    4.747377] Modules linked in: nfs_acl lockd grace sunrpc ip_tables btrfs xor raid6_pq sd_mod crc32c_intel firewire_ohci igb ahci
 firewire_core crc_itu_t dca libahci i915 libata i2c_algo_bit e1000e drm_kms_helper ptp syscopyarea sysfillrect pps_core sysimgblt f
b_sys_fops drm video
[    4.747385] CPU: 3 PID: 439 Comm: btrfs-cleaner Not tainted 4.13.2-1.el7.elrepo.x86_64 #1
[    4.747385] Hardware name: Supermicro X10SAE/X10SAE, BIOS 2.0a 05/09/2014
[    4.747386] task: ffff88040cdcae80 task.stack: ffffc900021f4000
[    4.747396] RIP: 0010:btrfs_update_device+0x1c5/0x1d0 [btrfs]
[    4.747396] RSP: 0018:ffffc900021f7d00 EFLAGS: 00010206
[    4.747397] RAX: 0000000000000fff RBX: ffff880407b7aa80 RCX: 0000001bc6c71e00
[    4.747397] RDX: ffff880000000000 RSI: ffff880404cd3f3c RDI: ffff880409417b58
[    4.747398] RBP: ffffc900021f7d48 R08: 0000000000003f60 R09: ffffc900021f7cb8
[    4.747398] R10: 0000000000001000 R11: 0000000000000003 R12: ffff88040559f800
[    4.747398] R13: 0000000000000000 R14: ffff880409417b58 R15: 0000000000003f3c
[    4.747399] FS:  0000000000000000(0000) GS:ffff88041fac0000(0000) knlGS:0000000000000000
[    4.747399] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[    4.747400] CR2: 00007f29c3000248 CR3: 00000004056a4000 CR4: 00000000001406e0
[    4.747400] Call Trace:
[    4.747410]  btrfs_remove_chunk+0x2fb/0x8b0 [btrfs]
[    4.747418]  btrfs_delete_unused_bgs+0x363/0x440 [btrfs]
[    4.747426]  cleaner_kthread+0x150/0x180 [btrfs]
[    4.747429]  kthread+0x109/0x140
[    4.747436]  ? btree_invalidatepage+0xa0/0xa0 [btrfs]
[    4.747437]  ? kthread_park+0x60/0x60
[    4.747439]  ret_from_fork+0x25/0x30
[    4.747439] Code: 10 00 00 00 4c 89 fe e8 8a 30 ff ff 4c 89 f7 e8 32 f6 fc ff e9 d3 fe ff ff b8 f4 ff ff ff e9 d4 fe ff ff 0f 1f 00 e8 bb 2e 9e e0 <0f> ff eb af 0f 1f 80 00 00 00 00 0f 1f 44 00 00 55 31 d2 be 02 
[    4.747450] ---[ end trace 1ef80a625983d73b ]---


I've recently done a rebalance as well as scrubs.  As well as     

mount -oremount,clear_cache $mountpoint

...and then a fresh reboot to get an untainted trace.

I'm running mainline kernel 4.13.2-1.el7.elrepo.x86_64

I don't see any side effects from this ... just frequent dmesg messages.
Comment 1 rrauenza 2017-09-18 15:19:18 UTC
I also did a btrfs check --repair on all the fs's -- the trace still occurs dozens of times a day.
Comment 2 rrauenza 2017-09-21 15:44:55 UTC
Per the mailing list, this was due to the size not being a multiple of 4k.

I used "btrfs fi show --raw /mnt" to see the size in bytes, and then ...

sudo btrfs filesystem resize N:SIZE /mnt

Where N was the disk number in the "btrfs fi show" output, and SIZE was the rounded down number of bytes that was a multiple of 4k. 

Qu Wenro says this would work as well:

> btrfs fi resize N:max <path>
>
> Or
>
> btrfs fi resize N:-1 <path>
>
> The first one will resize the devid N to its max size.
> The 2nd one will resize the devid N to current size - 1 (byte).
>
> Both will go through shrink routine, which will do the round_down.

Not closing because there was some discussion on the list between Qu and nborisov@suse.de about changing the error message or removing it or...?
Comment 3 martin 2017-09-27 21:01:09 UTC
Hit by this too...
Device added some time ago ( 4.12 epoch)
btrfs fi resize 5:max seems to have fixed it. (original size was not a multiple of 4k)

For the sake of completeness, my backtrace:
[147466.798669] ------------[ cut here ]------------                                                                                                                                                 
[147466.798687] WARNING: CPU: 0 PID: 7595 at fs/btrfs/ctree.h:1559 btrfs_update_device+0x1b3/0x1c0                                                                                                   
[147466.798690] Modules linked in: rfcomm cmac tun nls_iso8859_1 nls_cp437 vfat fat ctr ccm 8021q garp mrp bridge stp llc nft_reject_ipv4 nft_limit nf_conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_rejec
t_inet nf_reject_ipv4 nft_reject_ipv6 nf_reject_ipv6 nft_reject nft_masq_ipv4 nf_nat_masquerade_ipv4 nft_masq nft_counter nfnetlink_log nft_log nft_meta nft_set_bitmap nft_set_hash nft_set_rbtree $
ft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_tables_inet nf_tables_ipv6 nf_tables_ipv4 bnep radeon ath9k_htc i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_s$
s_fops ttm drm sch_fq_codel kvm_amd nf_conntrack_netlink nft_nat nf_nat kvm tpm_tis tpm_tis_core irqbypass pcspkr k10temp ath3k btusb nf_conntrack tpm btrtl btintel i2c_piix4 bluetooth nf_tables d$
bg input_leds ecdh_generic                                                                                      
[147466.798760]  crc16 evdev snd_hda_codec_realtek snd_hda_codec_generic snd_hda_codec_hdmi snd_hda_intel xhci_pci xhci_hcd nfnetlink acpi_cpufreq serio nfsd snd_hda_codec button snd_hwdep video a$
th_rpcgss snd_hda_core oid_registry snd_pcm snd_timer snd lockd soundcore grace bonding arc4 ath9k ath9k_common ath9k_hw led_class mac80211 ath cfg80211 rfkill nct6775 hwmon_vid hwmon imon(O) si21$
7(O) si2168(O) tbsecp3(O) tas2101(O) i2c_mux dvb_usb_af9015(O) dvb_usb_v2(O) dvb_usb_m920x(O) dvb_usb(O) dvb_core(O) rc_core(O) media(O) i2c_core dm_crypt algif_skcipher hid_generic usbhid hid crc$
10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 crypto_simd glue_helper cryptd alx mdio ohci_pci ehci_pci ohci_hcd ehci_hcd usbcore usb_common sunrpc dm_mod dax   
[147466.798835] CPU: 0 PID: 7595 Comm: btrfs Tainted: G        W  O    4.13.3-gentoo #1                                                                                                              
[147466.798839] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./FM2A88X-ITX+, BIOS P3.40 01/14/2016
[147466.798843] task: ffff92459c3f8f00 task.stack: ffffaf3985794000                                                                                                                                  
[147466.798849] RIP: 0010:btrfs_update_device+0x1b3/0x1c0                                                                                                                                            
[147466.798852] RSP: 0018:ffffaf3985797710 EFLAGS: 00010206                                                                                                                                          
[147466.798856] RAX: 0000000000000fff RBX: 0000000000000000 RCX: 000001d1c0e11e00                                                                                                                 
[147466.798859] RDX: 0000000000000004 RSI: 0000000000003e36 RDI: ffff92447dda9c70      
[147466.798862] RBP: ffffaf3985797758 R08: 0000000000003e3a R09: ffffaf39857976c8                               
[147466.798865] R10: 0000000000001000 R11: 0000000000000003 R12: ffff924813d3a770              
[147466.798868] R13: ffff9248199b8800 R14: 0000000000003e16 R15: ffff92447dda9c70
[147466.798872] FS:  00007f3bba7118c0(0000) GS:ffff92482ec00000(0000) knlGS:0000000000000000
[147466.798875] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033                              
[147466.798878] CR2: 00007f4f226260b0 CR3: 00000002bf8ae000 CR4: 00000000000406f0
[147466.798880] Call Trace:                                                      
[147466.798888]  btrfs_finish_chunk_alloc+0x126/0x4f0                                          
[147466.798895]  ? btrfs_insert_item+0x80/0xf0                                   
[147466.798901]  btrfs_create_pending_block_groups+0x12f/0x240                              
[147466.798906]  __btrfs_end_transaction+0x8d/0x2d0                                            
[147466.798911]  btrfs_end_transaction+0x10/0x18                                 
[147466.798915]  __btrfs_prealloc_file_range+0x34e/0x460   
[147466.798921]  btrfs_prealloc_file_range+0x13/0x18                                           
[147466.798926]  prealloc_file_extent_cluster+0x129/0x238
[147466.798931]  relocate_file_extent_cluster+0x7f/0x3d0
[147466.798936]  relocate_block_group+0x54c/0x670
[147466.798941]  btrfs_relocate_block_group+0x184/0x230
[147466.798945]  btrfs_relocate_chunk+0x36/0xc0
[147466.798948]  btrfs_balance+0xa7b/0x1340
[147466.798954]  ? try_to_wake_up+0x21f/0x448
[147466.798961]  btrfs_ioctl_balance+0x3a0/0x3b0
[147466.798965]  btrfs_ioctl+0xd81/0x2420
[147466.798971]  ? tty_write_unlock+0x31/0x38
[147466.798975]  ? tty_ldisc_deref+0x16/0x20
[147466.798979]  ? tty_write+0x1d8/0x2f0
[147466.798984]  ? n_tty_open+0xd0/0xd0
[147466.798989]  do_vfs_ioctl+0xa1/0x5c8
[147466.798994]  ? vfs_write+0x199/0x1b0
[147466.798999]  ? hrtimer_init+0x100/0x100
[147466.799003]  SyS_ioctl+0x79/0x90
[147466.799008]  entry_SYSCALL_64_fastpath+0x13/0x94
[147466.799012] RIP: 0033:0x7f3bb9778ca7
[147466.799014] RSP: 002b:00007ffdfce08818 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[147466.799019] RAX: ffffffffffffffda RBX: 0000000000000002 RCX: 00007f3bb9778ca7
[147466.799022] RDX: 00007ffdfce088b0 RSI: 00000000c4009420 RDI: 0000000000000003
[147466.799024] RBP: 0000000001f6a050 R08: 00007f3bba7118c0 R09: 00007f3bba7118c0
[147466.799027] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000000002
[147466.799030] R13: 0000000000000001 R14: 00007f3bb9a315a0 R15: 0000000000000000
[147466.799033] Code: 00 4c 89 ff 45 31 c0 ba 10 00 00 00 4c 89 f6 e8 34 37 ff ff 4c 89 ff e8 fc 0d fd ff e9 da fe ff ff b8 f4 ff ff ff e9 da fe ff ff <0f> ff eb b8 e8 f4 a2 d8 ff 0f 1f 40 00 0f 1$
 44 00 00 55 31 d2 
[147466.799084] ---[ end trace baf2843fc871fae3 ]---

Note You need to log in before you can comment on or make changes to this bug.