kernel BUG at fs/btrfs/ctree.h:1802!

kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

My server now reboots every 20mn or so, with this.
Sadly another BUG_ON() and it won't even tell me which filesystem
it's on

static inline u32 btrfs_extent_inline_ref_size(int type)
{
	if (type == BTRFS_TREE_BLOCK_REF_KEY ||
	    type == BTRFS_SHARED_BLOCK_REF_KEY)
		return sizeof(struct btrfs_extent_inline_ref);
	if (type == BTRFS_SHARED_DATA_REF_KEY)
		return sizeof(struct btrfs_shared_data_ref) +
		       sizeof(struct btrfs_extent_inline_ref);
	if (type == BTRFS_EXTENT_DATA_REF_KEY)
		return sizeof(struct btrfs_extent_data_ref) +
		       offsetof(struct btrfs_extent_inline_ref, offset);
	BUG();
	return 0;
}



[ 1399.728735] ------------[ cut here ]------------
[ 1399.744149] kernel BUG at fs/btrfs/ctree.h:1802!
[ 1399.759400] invalid opcode: 0000 [#1] PREEMPT SMP
[ 1399.774892] Modules linked in: veth ip6table_filter ip6_tables ebtable_nat ebtables ppdev lp xt_addrtype br_netfilter bridge stp llc tun autofs4 softdog binfmt_misc ftdi_sio nfsd auth_rpcgss nfs_acl nfs lockd grace fscache sunrpc ipt_REJECT nf_reject_ipv4 xt_conntrack xt_mark xt_nat xt_tcpudp nf_log_ipv4 nf_log_common xt_LOG iptable_mangle iptable_filter lm85 hwmon_vid pl2303 dm_snapshot dm_bufio iptable_nat ip_tables nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_conntrack_ftp ipt_MASQUERADE nf_nat_masquerade_ipv4 nf_nat nf_conntrack x_tables sg st snd_pcm_oss snd_mixer_oss bcache kvm_intel kvm irqbypass snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_cmipci snd_hda_codec snd_mpu401_uart eeepc_wmi snd_opl3_lib snd_hda_core snd_rawmidi asus_wmi sparse_keymap snd_seq_device asix snd_hwdep
[ 1399.997524]  rc_ati_x10 tpm_infineon snd_pcm rfkill snd_timer ati_remote usbnet tpm_tis usbserial libphy i915 rc_core hwmon tpm_tis_core snd wmi_bmof mei_me lpc_ich i2c_i801 soundcore battery pcspkr evdev input_leds tpm wmi parport_pc parport e1000e ptp pps_core fuse raid456 multipath mmc_block mmc_core lrw ablk_helper dm_crypt dm_mod async_raid6_recov async_pq async_xor async_memcpy async_tx crc32c_intel blowfish_x86_64 blowfish_common pcbc aesni_intel aes_x86_64 crypto_simd glue_helper cryptd xhci_pci ehci_pci mvsas ehci_hcd xhci_hcd libsas r8169 scsi_transport_sas mii usbcore sata_sil24 thermal fan [last unloaded: ftdi_sio]
[ 1400.174918] CPU: 0 PID: 80 Comm: kworker/u16:1 Tainted: G     U  W       4.13.12-amd64-stkreg-sysrq-20171018 #2
[ 1400.206640] Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 3904 04/27/2013
[ 1400.235418] Workqueue: btrfs-extent-refs btrfs_extent_refs_helper
[ 1400.255104] task: ffff8a94fa750180 task.stack: ffffb632c3404000
[ 1400.274346] RIP: 0010:btrfs_extent_inline_ref_size+0x29/0x39
[ 1400.292749] RSP: 0018:ffffb632c3407b28 EFLAGS: 00210297
[ 1400.309756] RAX: 000000000000001d RBX: ffff8a94f59f4a80 RCX: ffff8a9127287000
[ 1400.332482] RDX: 0000000000002000 RSI: 0000000000002598 RDI: 0000000000000000
[ 1400.355188] RBP: ffffb632c3407b28 R08: ffffb632c3407ae8 R09: ffffb632c3407af0
[ 1400.377871] R10: 0000000000000000 R11: 0000000000002000 R12: 0000000000000000
[ 1400.400537] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000002598
[ 1400.423912] FS:  0000000000000000(0000) GS:ffff8a951e200000(0000) knlGS:0000000000000000
[ 1400.449416] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1400.467878] CR2: 000000000be9c3f8 CR3: 00000004b5c09000 CR4: 00000000001406f0
[ 1400.490491] Call Trace:
[ 1400.499066]  lookup_inline_extent_backref+0x2ff/0x411
[ 1400.515452]  ? ___cache_free+0x200/0x25c
[ 1400.528390]  __btrfs_free_extent+0xeb/0xa5d
[ 1400.542077]  ? ___cache_free+0x1e8/0x25c
[ 1400.554950]  __btrfs_run_delayed_refs+0xb6c/0xd52
[ 1400.570208]  ? _raw_spin_unlock_irqrestore+0x14/0x24
[ 1400.586191]  ? try_to_wake_up+0x251/0x277
[ 1400.599288]  btrfs_run_delayed_refs+0x77/0x1a1
[ 1400.613653]  delayed_ref_async_start+0x5e/0x9b
[ 1400.628580]  btrfs_scrubparity_helper+0x111/0x271
[ 1400.644271]  ? pwq_activate_delayed_work+0x4d/0x5b
[ 1400.659614]  btrfs_extent_refs_helper+0xe/0x10
[ 1400.673972]  process_one_work+0x179/0x2a5
[ 1400.686951]  worker_thread+0x1b1/0x262
[ 1400.699155]  ? rescuer_thread+0x273/0x273
[ 1400.712069]  kthread+0xfb/0x100
[ 1400.722354]  ? init_completion+0x24/0x24
[ 1400.734949]  ret_from_fork+0x25/0x30
[ 1400.746497] Code: 5d c3 55 81 ff b0 00 00 00 48 89 e5 74 1f 81 ff b6 00 00 00 74 17 81 ff b8 00 00 00 74 16 81 ff b2 00 00 00 b8 1d 00 00 00 74 0e <0f> 0b b8 09 00 00 00 eb 05 b8 0d 00 00 00 5d c3 55 48 89 f0 48
[ 1400.804753] RIP: btrfs_extent_inline_ref_size+0x29/0x39 RSP: ffffb632c3407b28
[ 1400.827109] ---[ end trace 70850509bfd007d7 ]---
[ 1400.841833] Kernel panic - not syncing: Fatal exception
[ 1400.858356] Kernel Offset: 0x17000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)


-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

Sorry, was missing the kernel number in the subject, just fixed that.

On Thu, Nov 16, 2017 at 09:04:45AM -0800, Marc MERLIN wrote:
> My server now reboots every 20mn or so, with this.
> Sadly another BUG_ON() and it won't even tell me which filesystem
> it's on
> 
> static inline u32 btrfs_extent_inline_ref_size(int type)
> {
> 	if (type == BTRFS_TREE_BLOCK_REF_KEY ||
> 	    type == BTRFS_SHARED_BLOCK_REF_KEY)
> 		return sizeof(struct btrfs_extent_inline_ref);
> 	if (type == BTRFS_SHARED_DATA_REF_KEY)
> 		return sizeof(struct btrfs_shared_data_ref) +
> 		       sizeof(struct btrfs_extent_inline_ref);
> 	if (type == BTRFS_EXTENT_DATA_REF_KEY)
> 		return sizeof(struct btrfs_extent_data_ref) +
> 		       offsetof(struct btrfs_extent_inline_ref, offset);
> 	BUG();
> 	return 0;
> }
> 
> 
> 
> [ 1399.728735] ------------[ cut here ]------------
> [ 1399.744149] kernel BUG at fs/btrfs/ctree.h:1802!
> [ 1399.759400] invalid opcode: 0000 [#1] PREEMPT SMP
> [ 1399.774892] Modules linked in: veth ip6table_filter ip6_tables ebtable_nat ebtables ppdev lp xt_addrtype br_netfilter bridge stp llc tun autofs4 softdog binfmt_misc ftdi_sio nfsd auth_rpcgss nfs_acl nfs lockd grace fscache sunrpc ipt_REJECT nf_reject_ipv4 xt_conntrack xt_mark xt_nat xt_tcpudp nf_log_ipv4 nf_log_common xt_LOG iptable_mangle iptable_filter lm85 hwmon_vid pl2303 dm_snapshot dm_bufio iptable_nat ip_tables nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_conntrack_ftp ipt_MASQUERADE nf_nat_masquerade_ipv4 nf_nat nf_conntrack x_tables sg st snd_pcm_oss snd_mixer_oss bcache kvm_intel kvm irqbypass snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel snd_cmipci snd_hda_codec snd_mpu401_uart eeepc_wmi snd_opl3_lib snd_hda_core snd_rawmidi asus_wmi sparse_keymap snd_seq_device asix snd_hwdep
> [ 1399.997524]  rc_ati_x10 tpm_infineon snd_pcm rfkill snd_timer ati_remote usbnet tpm_tis usbserial libphy i915 rc_core hwmon tpm_tis_core snd wmi_bmof mei_me lpc_ich i2c_i801 soundcore battery pcspkr evdev input_leds tpm wmi parport_pc parport e1000e ptp pps_core fuse raid456 multipath mmc_block mmc_core lrw ablk_helper dm_crypt dm_mod async_raid6_recov async_pq async_xor async_memcpy async_tx crc32c_intel blowfish_x86_64 blowfish_common pcbc aesni_intel aes_x86_64 crypto_simd glue_helper cryptd xhci_pci ehci_pci mvsas ehci_hcd xhci_hcd libsas r8169 scsi_transport_sas mii usbcore sata_sil24 thermal fan [last unloaded: ftdi_sio]
> [ 1400.174918] CPU: 0 PID: 80 Comm: kworker/u16:1 Tainted: G     U  W       4.13.12-amd64-stkreg-sysrq-20171018 #2
> [ 1400.206640] Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 3904 04/27/2013
> [ 1400.235418] Workqueue: btrfs-extent-refs btrfs_extent_refs_helper
> [ 1400.255104] task: ffff8a94fa750180 task.stack: ffffb632c3404000
> [ 1400.274346] RIP: 0010:btrfs_extent_inline_ref_size+0x29/0x39
> [ 1400.292749] RSP: 0018:ffffb632c3407b28 EFLAGS: 00210297
> [ 1400.309756] RAX: 000000000000001d RBX: ffff8a94f59f4a80 RCX: ffff8a9127287000
> [ 1400.332482] RDX: 0000000000002000 RSI: 0000000000002598 RDI: 0000000000000000
> [ 1400.355188] RBP: ffffb632c3407b28 R08: ffffb632c3407ae8 R09: ffffb632c3407af0
> [ 1400.377871] R10: 0000000000000000 R11: 0000000000002000 R12: 0000000000000000
> [ 1400.400537] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000002598
> [ 1400.423912] FS:  0000000000000000(0000) GS:ffff8a951e200000(0000) knlGS:0000000000000000
> [ 1400.449416] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 1400.467878] CR2: 000000000be9c3f8 CR3: 00000004b5c09000 CR4: 00000000001406f0
> [ 1400.490491] Call Trace:
> [ 1400.499066]  lookup_inline_extent_backref+0x2ff/0x411
> [ 1400.515452]  ? ___cache_free+0x200/0x25c
> [ 1400.528390]  __btrfs_free_extent+0xeb/0xa5d
> [ 1400.542077]  ? ___cache_free+0x1e8/0x25c
> [ 1400.554950]  __btrfs_run_delayed_refs+0xb6c/0xd52
> [ 1400.570208]  ? _raw_spin_unlock_irqrestore+0x14/0x24
> [ 1400.586191]  ? try_to_wake_up+0x251/0x277
> [ 1400.599288]  btrfs_run_delayed_refs+0x77/0x1a1
> [ 1400.613653]  delayed_ref_async_start+0x5e/0x9b
> [ 1400.628580]  btrfs_scrubparity_helper+0x111/0x271
> [ 1400.644271]  ? pwq_activate_delayed_work+0x4d/0x5b
> [ 1400.659614]  btrfs_extent_refs_helper+0xe/0x10
> [ 1400.673972]  process_one_work+0x179/0x2a5
> [ 1400.686951]  worker_thread+0x1b1/0x262
> [ 1400.699155]  ? rescuer_thread+0x273/0x273
> [ 1400.712069]  kthread+0xfb/0x100
> [ 1400.722354]  ? init_completion+0x24/0x24
> [ 1400.734949]  ret_from_fork+0x25/0x30
> [ 1400.746497] Code: 5d c3 55 81 ff b0 00 00 00 48 89 e5 74 1f 81 ff b6 00 00 00 74 17 81 ff b8 00 00 00 74 16 81 ff b2 00 00 00 b8 1d 00 00 00 74 0e <0f> 0b b8 09 00 00 00 eb 05 b8 0d 00 00 00 5d c3 55 48 89 f0 48
> [ 1400.804753] RIP: btrfs_extent_inline_ref_size+0x29/0x39 RSP: ffffb632c3407b28
> [ 1400.827109] ---[ end trace 70850509bfd007d7 ]---
> [ 1400.841833] Kernel panic - not syncing: Fatal exception
> [ 1400.858356] Kernel Offset: 0x17000000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
> 
> 
> -- 
> "A mouse is a device used to point at the xterm you want to type in" - A.S.R.
> Microsoft is to operating systems ....
>                                       .... what McDonalds is to gourmet cooking
> Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901
> 

-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Holger Hoffstätte]

On 11/16/17 18:07, Marc MERLIN wrote:
> Sorry, was missing the kernel number in the subject, just fixed that.
> 
> On Thu, Nov 16, 2017 at 09:04:45AM -0800, Marc MERLIN wrote:
>> My server now reboots every 20mn or so, with this.
>> Sadly another BUG_ON() and it won't even tell me which filesystem
>> it's on
>>
>> static inline u32 btrfs_extent_inline_ref_size(int type)
>> {
>> 	if (type == BTRFS_TREE_BLOCK_REF_KEY ||
>> 	    type == BTRFS_SHARED_BLOCK_REF_KEY)
>> 		return sizeof(struct btrfs_extent_inline_ref);
>> 	if (type == BTRFS_SHARED_DATA_REF_KEY)
>> 		return sizeof(struct btrfs_shared_data_ref) +
>> 		       sizeof(struct btrfs_extent_inline_ref);
>> 	if (type == BTRFS_EXTENT_DATA_REF_KEY)
>> 		return sizeof(struct btrfs_extent_data_ref) +
>> 		       offsetof(struct btrfs_extent_inline_ref, offset);
>> 	BUG();
>> 	return 0;
>> }

This BUG() was recently removed and seems to be caused by some kind
of persistent corruption, which is seen as invalid inline extent.
See [1], [2] for details. Maybe you can backport them?
Alternatively just give 4.14 a whirl, it's great.

-h

[1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=167ce953ca55bdee20fe56c3c0fa51002435f745
[2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=4335958de2a43c6790c7f6aa0682aa7189983fa4

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

On Thu, Nov 16, 2017 at 06:27:44PM +0100, Holger Hoffstätte wrote:
> On 11/16/17 18:07, Marc MERLIN wrote:
> > Sorry, was missing the kernel number in the subject, just fixed that.
> > 
> > On Thu, Nov 16, 2017 at 09:04:45AM -0800, Marc MERLIN wrote:
> >> My server now reboots every 20mn or so, with this.
> >> Sadly another BUG_ON() and it won't even tell me which filesystem
> >> it's on
> >>
> >> static inline u32 btrfs_extent_inline_ref_size(int type)
> >> {
> >> 	if (type == BTRFS_TREE_BLOCK_REF_KEY ||
> >> 	    type == BTRFS_SHARED_BLOCK_REF_KEY)
> >> 		return sizeof(struct btrfs_extent_inline_ref);
> >> 	if (type == BTRFS_SHARED_DATA_REF_KEY)
> >> 		return sizeof(struct btrfs_shared_data_ref) +
> >> 		       sizeof(struct btrfs_extent_inline_ref);
> >> 	if (type == BTRFS_EXTENT_DATA_REF_KEY)
> >> 		return sizeof(struct btrfs_extent_data_ref) +
> >> 		       offsetof(struct btrfs_extent_inline_ref, offset);
> >> 	BUG();
> >> 	return 0;
> >> }
> 
> This BUG() was recently removed and seems to be caused by some kind
> of persistent corruption, which is seen as invalid inline extent.
> See [1], [2] for details. Maybe you can backport them?
> Alternatively just give 4.14 a whirl, it's great.
> 
> -h
> 
> [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=167ce953ca55bdee20fe56c3c0fa51002435f745
> [2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=4335958de2a43c6790c7f6aa0682aa7189983fa4

First thanks a lot for the quick reply, it was super timely considering
my server was rebooting every 20mn :)
I've now been running 4.14 for a couple of hours, and things seem ok
btrfs-wise.

So, just so that I understand:
1) I do have some kind of FS problem/corruption (minor? major?)

2) it started crashing 4.9.36 and then 4.13 today, every 20mn, probably due to some background
cleaner process that kept starting and hitting the problem spot

3) 4.14 does not crash anymore, but it doesn't even report any problem either. Does it mean
the error that crashed the old kernel is minor enough that the new kernel doesn't bother even
logging it?

4) I just ran scrub on the filesystem and it ran fine.

Sadly, while the BUG_ON was another one that failed to say which
mountpoint was affected, through painful trial and error, I think I
found out that it was affecting the root filesystem.
Doing a check or check --repair on that FS will be a major pain (need a rescue
media with the right version of dmcrypt, bcache, btrfs kernel, and btrfs progs)

I'm asusming that running btrfs check --force on a mounted filesystem
that is being used is not going to give useful results, unless I leave
the FS read only. Correct?


As for 4.14, the serial console code seems broken though, I can't get login or bash
to work anymore on them:
[ 2786.305004] INFO: task login:5636 blocked for more than 120 seconds.
[ 2786.324648]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
[ 2786.347692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2786.371742] login           D    0  5636      1 0xa0020006
[ 2786.388826] Call Trace:
[ 2786.396756]  __schedule+0x4b3/0x5bd
[ 2786.408077]  schedule+0x89/0x9a
[ 2786.418070]  schedule_timeout+0x43/0x101
[ 2786.430728]  ? default_wake_function+0x12/0x14
[ 2786.444620]  ? woken_wake_function+0x11/0x13
[ 2786.457967]  ldsem_down_write+0xe0/0x1a8
[ 2786.470293]  ? ldsem_down_write+0xe0/0x1a8
[ 2786.483143]  ? __wake_up_common_lock+0xa6/0xcf
[ 2786.497039]  tty_ldisc_lock+0x16/0x30
[ 2786.508587]  ? tty_ldisc_lock+0x16/0x30
[ 2786.520655]  tty_ldisc_hangup+0xbb/0x170
[ 2786.533000]  __tty_hangup+0x15f/0x21d
[ 2786.544541]  tty_vhangup_session+0x13/0x15
[ 2786.557388]  disassociate_ctty+0x51/0x209
[ 2786.570004]  do_exit+0x43a/0x923
[ 2786.580262]  ? recalc_sigpending_tsk+0x42/0x49
[ 2786.594120]  do_group_exit+0x6c/0xa5
[ 2786.605419]  get_signal+0x46b/0x4b3
[ 2786.616464]  do_signal+0x37/0x5ed
[ 2786.626969]  ? list_add+0x34/0x34
[ 2786.637474]  ? C_SYSC_wait4+0x49/0x99
[ 2786.649099]  ? handle_mm_fault+0x10f/0x17f
[ 2786.661968]  prepare_exit_to_usermode+0x94/0xef
[ 2786.676115]  syscall_return_slowpath+0xb9/0xd9
[ 2786.690035]  do_fast_syscall_32+0xc3/0xfe
[ 2786.702897]  entry_SYSENTER_compat+0x4c/0x5b
[ 2786.716272] RIP: 0023:0xf7f45c29
[ 2786.726496] RSP: 002b:00000000ffb5d0f0 EFLAGS: 00000246 ORIG_RAX: 0000000000000072
[ 2786.749827] RAX: fffffffffffffe00 RBX: 00000000ffffffff RCX: 0000000000000000
[ 2786.772104] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000080504ec
[ 2786.794087] RBP: 00000000ffb5f638 R08: 0000000000000000 R09: 0000000000000000
[ 2786.794088] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 2786.794088] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000

[ 2665.988277] INFO: task bash:5685 blocked for more than 120 seconds.
[ 2665.988278]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
[ 2665.988279] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2665.988281] bash            D    0  5685   5636 0xa0020086
[ 2665.988284] Call Trace:
[ 2665.988288]  __schedule+0x4b3/0x5bd
[ 2665.988291]  schedule+0x89/0x9a
[ 2665.988293]  schedule_preempt_disabled+0x15/0x1e
[ 2665.988294]  __mutex_lock.isra.1+0x16d/0x2e0
[ 2665.988298]  __mutex_lock_slowpath+0x13/0x15
[ 2665.988300]  ? __mutex_lock_slowpath+0x13/0x15
[ 2665.988301]  mutex_lock+0x2a/0x2d
[ 2665.988304]  tty_lock+0x31/0x3c
[ 2665.988306]  tty_release+0x48/0x53c
[ 2665.988310]  __fput+0xf0/0x190
[ 2665.988312]  ____fput+0xe/0x10
[ 2665.988314]  task_work_run+0x79/0x8c
[ 2665.988317]  do_exit+0x447/0x923
[ 2665.988320]  ? recalc_sigpending_tsk+0x42/0x49
[ 2665.988322]  do_group_exit+0x6c/0xa5
[ 2665.988323]  get_signal+0x46b/0x4b3
[ 2665.988327]  do_signal+0x37/0x5ed
[ 2665.988329]  ? group_send_sig_info+0x4e/0x56
[ 2665.988331]  ? SYSC_kill+0xa8/0x1b1
[ 2665.988333]  ? do_sigaction+0xbe/0x18b
[ 2665.988335]  ? __audit_syscall_entry+0xc2/0xe6
[ 2665.988338]  prepare_exit_to_usermode+0x94/0xef
[ 2665.988341]  syscall_return_slowpath+0xb9/0xd9
[ 2665.988343]  do_fast_syscall_32+0xc3/0xfe
[ 2665.988345]  entry_SYSENTER_compat+0x4c/0x5b
[ 2665.988347] RIP: 0023:0xf7f24c29
[ 2665.988348] RSP: 002b:00000000ffccf9ec EFLAGS: 00000206 ORIG_RAX: 0000000000000025
[ 2665.988350] RAX: 0000000000000000 RBX: 0000000000001635 RCX: 0000000000000001
[ 2665.988351] RDX: 0000000000000001 RSI: 00000000080a0310 RDI: 0000000000000000
[ 2665.988351] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
[ 2665.988352] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
[ 2665.988353] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000

Thanks,
Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Holger Hoffstätte]

On 11/16/17 22:45, Marc MERLIN wrote:
(snip)
>> This BUG() was recently removed and seems to be caused by some kind
>> of persistent corruption, which is seen as invalid inline extent.
>> See [1], [2] for details. Maybe you can backport them?
>> Alternatively just give 4.14 a whirl, it's great.
>>
>> -h
>>
>> [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=167ce953ca55bdee20fe56c3c0fa51002435f745
>> [2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=4335958de2a43c6790c7f6aa0682aa7189983fa4
> 
> First thanks a lot for the quick reply, it was super timely considering
> my server was rebooting every 20mn :)
> I've now been running 4.14 for a couple of hours, and things seem ok
> btrfs-wise.

Don't pop the champagne just yet, I just read that apprently 4.14 broke
bcache for some people [1]. Not sure how much that affects you, but it might
well make things worse. Yeah, I know, wonderful.

> So, just so that I understand:
> 1) I do have some kind of FS problem/corruption (minor? major?)

All I know is what's in those commits, I just remembered the description. ;)
If I understand the patches correctly you're still supposed to get an
"invalid extent inline ref type" message.

> 2) it started crashing 4.9.36 and then 4.13 today, every 20mn, probably due to some background
> cleaner process that kept starting and hitting the problem spot

Sounds like.

> 3) 4.14 does not crash anymore, but it doesn't even report any problem either. Does it mean
> the error that crashed the old kernel is minor enough that the new kernel doesn't bother even
> logging it?

See above, you should still get a warning. OTOH it's hard to tell what is
going on when you seem to have dm/dmcrypt/bcache lasagne going on..

> 4) I just ran scrub on the filesystem and it ran fine.

That's not too depressing. :)

> I'm asusming that running btrfs check --force on a mounted filesystem
> that is being used is not going to give useful results, unless I leave
> the FS read only. Correct?

Think so, yes.

> As for 4.14, the serial console code seems broken though, I can't get login or bash
> to work anymore on them:
> [ 2786.305004] INFO: task login:5636 blocked for more than 120 seconds.
> [ 2786.324648]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
> [ 2786.347692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 2786.371742] login           D    0  5636      1 0xa0020006

I'm out. :/

-h

[1] https://marc.info/?t=151082126000001

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

On Thu, Nov 16, 2017 at 11:32:33PM +0100, Holger Hoffstätte wrote:
> Don't pop the champagne just yet, I just read that apprently 4.14 broke
> bcache for some people [1]. Not sure how much that affects you, but it might
> well make things worse. Yeah, I know, wonderful.

Oh my, that's actually pretty terrible.
I've just reverted both my machines to 3.13, the last thing I need is more
btrfs corruption.

I'm also starting to question if I should just drop bcache. It does help
access to a big and slow-ish array, but corruption and periodic btrfs
full rebuilds is not something I can afford to do timewise :-/

> > As for 4.14, the serial console code seems broken though, I can't get login or bash
> > to work anymore on them:
> > [ 2786.305004] INFO: task login:5636 blocked for more than 120 seconds.
> > [ 2786.324648]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
> > [ 2786.347692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > [ 2786.371742] login           D    0  5636      1 0xa0020006
> 
> I'm out. :/

Yeah, I didn't expect you to know, or this list even, just warning that 4.14
is not "that great" yet (although that was before the "bcache will corrupt
your stuff", which now makes it "terrible" :( ).

On the plus side, I'm back to 4.13.12 and it hasn't crashed yet, so maybe
4.14 fixed the issue I had (wishful thinking)

Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/  

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Roman Mamedov]

On Thu, 16 Nov 2017 16:12:56 -0800
Marc MERLIN <marc@merlins.org> wrote:

> On Thu, Nov 16, 2017 at 11:32:33PM +0100, Holger Hoffstätte wrote:
> > Don't pop the champagne just yet, I just read that apprently 4.14 broke
> > bcache for some people [1]. Not sure how much that affects you, but it might
> > well make things worse. Yeah, I know, wonderful.
> 
> Oh my, that's actually pretty terrible.
> I've just reverted both my machines to 3.13, the last thing I need is more
> btrfs corruption.

Why so far back though, the latest 4.4 and 4.9 are both good series and run
without issues for me since a long time. Or perhaps you meant 4.13 :)

> I'm also starting to question if I should just drop bcache. It does help
> access to a big and slow-ish array, but corruption and periodic btrfs
> full rebuilds is not something I can afford to do timewise :-/

I suggest that you try lvmcache instead. It's much more flexible than bcache,
does pretty much the same job, and has much less of the "hacky" feel to it.

-- 
With respect,
Roman

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

On Fri, Nov 17, 2017 at 10:41:48AM +0500, Roman Mamedov wrote:
> On Thu, 16 Nov 2017 16:12:56 -0800
> Marc MERLIN <marc@merlins.org> wrote:
> 
> > On Thu, Nov 16, 2017 at 11:32:33PM +0100, Holger Hoffstätte wrote:
> > > Don't pop the champagne just yet, I just read that apprently 4.14 broke
> > > bcache for some people [1]. Not sure how much that affects you, but it might
> > > well make things worse. Yeah, I know, wonderful.
> > 
> > Oh my, that's actually pretty terrible.
> > I've just reverted both my machines to 3.13, the last thing I need is more
> > btrfs corruption.
> 
> Why so far back though, the latest 4.4 and 4.9 are both good series and run
> without issues for me since a long time. Or perhaps you meant 4.13 :)
 
Typo indeed, I meant 4.13.

> I suggest that you try lvmcache instead. It's much more flexible than bcache,
> does pretty much the same job, and has much less of the "hacky" feel to it.

I can read up on it, it's going to be a big pain to convert from one to
the other, but I can look at it for new filesystems.

Thanks,
Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Marc MERLIN]

On Thu, Nov 16, 2017 at 09:53:15PM -0800, Marc MERLIN wrote:
> > I suggest that you try lvmcache instead. It's much more flexible than bcache,
> > does pretty much the same job, and has much less of the "hacky" feel to it.
> 
> I can read up on it, it's going to be a big pain to convert from one to
> the other, but I can look at it for new filesystems.

I had a quick read. As expected, it's slower since it goes through all
the LVM overhead that I got rid of recently
https://github.com/stec-inc/EnhanceIO/wiki/PERFORMANCE-COMPARISON-AMONG-dm-cache,-bcache-and-EnhanceIO

Given the pain it would be for me to switch, I'm going to stick with
bcache and hope it improves.
But just to be safe, I'm going to stick to this:
echo writearound > /sys/block/bcache0/bcache/cache_mode

Probably my issues were having writes go through bcache, writeback on
one drive even.
I'll go back to the safest setting and hope for the best.

Marc
-- 
"A mouse is a device used to point at the xterm you want to type in" - A.S.R.
Microsoft is to operating systems ....
                                      .... what McDonalds is to gourmet cooking
Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Holger Hoffstätte]

On 11/17/17 18:48, Marc MERLIN wrote:
> On Thu, Nov 16, 2017 at 09:53:15PM -0800, Marc MERLIN wrote:
>>> I suggest that you try lvmcache instead. It's much more flexible than bcache,
>>> does pretty much the same job, and has much less of the "hacky" feel to it.
>>
>> I can read up on it, it's going to be a big pain to convert from one to
>> the other, but I can look at it for new filesystems.
> 
> I had a quick read. As expected, it's slower since it goes through all
> the LVM overhead that I got rid of recently
> https://github.com/stec-inc/EnhanceIO/wiki/PERFORMANCE-COMPARISON-AMONG-dm-cache,-bcache-and-EnhanceIO
> 
> Given the pain it would be for me to switch, I'm going to stick with
> bcache and hope it improves.

My understanding is that bcache until recently was more or less unmaintained,
but got quite a few patches for 4.14 and now has a new maintainer as well.
So things are looking up.

-h

Re: 4.13.12: kernel BUG at fs/btrfs/ctree.h:1802!

[Liu Bo]

On Thu, Nov 16, 2017 at 01:45:51PM -0800, Marc MERLIN wrote:
> On Thu, Nov 16, 2017 at 06:27:44PM +0100, Holger Hoffstätte wrote:
> > On 11/16/17 18:07, Marc MERLIN wrote:
> > > Sorry, was missing the kernel number in the subject, just fixed that.
> > > 
> > > On Thu, Nov 16, 2017 at 09:04:45AM -0800, Marc MERLIN wrote:
> > >> My server now reboots every 20mn or so, with this.
> > >> Sadly another BUG_ON() and it won't even tell me which filesystem
> > >> it's on
> > >>
> > >> static inline u32 btrfs_extent_inline_ref_size(int type)
> > >> {
> > >> 	if (type == BTRFS_TREE_BLOCK_REF_KEY ||
> > >> 	    type == BTRFS_SHARED_BLOCK_REF_KEY)
> > >> 		return sizeof(struct btrfs_extent_inline_ref);
> > >> 	if (type == BTRFS_SHARED_DATA_REF_KEY)
> > >> 		return sizeof(struct btrfs_shared_data_ref) +
> > >> 		       sizeof(struct btrfs_extent_inline_ref);
> > >> 	if (type == BTRFS_EXTENT_DATA_REF_KEY)
> > >> 		return sizeof(struct btrfs_extent_data_ref) +
> > >> 		       offsetof(struct btrfs_extent_inline_ref, offset);
> > >> 	BUG();
> > >> 	return 0;
> > >> }
> > 
> > This BUG() was recently removed and seems to be caused by some kind
> > of persistent corruption, which is seen as invalid inline extent.
> > See [1], [2] for details. Maybe you can backport them?
> > Alternatively just give 4.14 a whirl, it's great.
> > 
> > -h
> > 
> > [1] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=167ce953ca55bdee20fe56c3c0fa51002435f745
> > [2] https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=4335958de2a43c6790c7f6aa0682aa7189983fa4
> 
> First thanks a lot for the quick reply, it was super timely considering
> my server was rebooting every 20mn :)
> I've now been running 4.14 for a couple of hours, and things seem ok
> btrfs-wise.
> 
> So, just so that I understand:
> 1) I do have some kind of FS problem/corruption (minor? major?)
>

As of my understanding, extent inline refs mismatch could come from
some runtime memory error, so btrfs carries the wrong extent inline
refs info. and calculate checksum in metadata block and then write it
to disk, the next time you read it, the checksum says OK, but extent
inline refs is invalid.  TBH, I could think of another reason.

> 2) it started crashing 4.9.36 and then 4.13 today, every 20mn, probably due to some background
> cleaner process that kept starting and hitting the problem spot
> 
> 3) 4.14 does not crash anymore, but it doesn't even report any problem either. Does it mean
> the error that crashed the old kernel is minor enough that the new kernel doesn't bother even
> logging it?
>

If it doesn't cause problems during scrub, I'd say probably we're safe
now, otherwise at least you would see some error shown in dmesg and
some operations from userspace would be aborted.

No idea why the below hang occurs..

Thanks,

-liubo

> 4) I just ran scrub on the filesystem and it ran fine.
> 
> Sadly, while the BUG_ON was another one that failed to say which
> mountpoint was affected, through painful trial and error, I think I
> found out that it was affecting the root filesystem.
> Doing a check or check --repair on that FS will be a major pain (need a rescue
> media with the right version of dmcrypt, bcache, btrfs kernel, and btrfs progs)
> 
> I'm asusming that running btrfs check --force on a mounted filesystem
> that is being used is not going to give useful results, unless I leave
> the FS read only. Correct?
> 
> 
> As for 4.14, the serial console code seems broken though, I can't get login or bash
> to work anymore on them:
> [ 2786.305004] INFO: task login:5636 blocked for more than 120 seconds.
> [ 2786.324648]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
> [ 2786.347692] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 2786.371742] login           D    0  5636      1 0xa0020006
> [ 2786.388826] Call Trace:
> [ 2786.396756]  __schedule+0x4b3/0x5bd
> [ 2786.408077]  schedule+0x89/0x9a
> [ 2786.418070]  schedule_timeout+0x43/0x101
> [ 2786.430728]  ? default_wake_function+0x12/0x14
> [ 2786.444620]  ? woken_wake_function+0x11/0x13
> [ 2786.457967]  ldsem_down_write+0xe0/0x1a8
> [ 2786.470293]  ? ldsem_down_write+0xe0/0x1a8
> [ 2786.483143]  ? __wake_up_common_lock+0xa6/0xcf
> [ 2786.497039]  tty_ldisc_lock+0x16/0x30
> [ 2786.508587]  ? tty_ldisc_lock+0x16/0x30
> [ 2786.520655]  tty_ldisc_hangup+0xbb/0x170
> [ 2786.533000]  __tty_hangup+0x15f/0x21d
> [ 2786.544541]  tty_vhangup_session+0x13/0x15
> [ 2786.557388]  disassociate_ctty+0x51/0x209
> [ 2786.570004]  do_exit+0x43a/0x923
> [ 2786.580262]  ? recalc_sigpending_tsk+0x42/0x49
> [ 2786.594120]  do_group_exit+0x6c/0xa5
> [ 2786.605419]  get_signal+0x46b/0x4b3
> [ 2786.616464]  do_signal+0x37/0x5ed
> [ 2786.626969]  ? list_add+0x34/0x34
> [ 2786.637474]  ? C_SYSC_wait4+0x49/0x99
> [ 2786.649099]  ? handle_mm_fault+0x10f/0x17f
> [ 2786.661968]  prepare_exit_to_usermode+0x94/0xef
> [ 2786.676115]  syscall_return_slowpath+0xb9/0xd9
> [ 2786.690035]  do_fast_syscall_32+0xc3/0xfe
> [ 2786.702897]  entry_SYSENTER_compat+0x4c/0x5b
> [ 2786.716272] RIP: 0023:0xf7f45c29
> [ 2786.726496] RSP: 002b:00000000ffb5d0f0 EFLAGS: 00000246 ORIG_RAX: 0000000000000072
> [ 2786.749827] RAX: fffffffffffffe00 RBX: 00000000ffffffff RCX: 0000000000000000
> [ 2786.772104] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00000000080504ec
> [ 2786.794087] RBP: 00000000ffb5f638 R08: 0000000000000000 R09: 0000000000000000
> [ 2786.794088] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
> [ 2786.794088] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
> 
> [ 2665.988277] INFO: task bash:5685 blocked for more than 120 seconds.
> [ 2665.988278]       Tainted: G     U  W       4.14.0-amd64-stkreg-sysrq-20171018 #1
> [ 2665.988279] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [ 2665.988281] bash            D    0  5685   5636 0xa0020086
> [ 2665.988284] Call Trace:
> [ 2665.988288]  __schedule+0x4b3/0x5bd
> [ 2665.988291]  schedule+0x89/0x9a
> [ 2665.988293]  schedule_preempt_disabled+0x15/0x1e
> [ 2665.988294]  __mutex_lock.isra.1+0x16d/0x2e0
> [ 2665.988298]  __mutex_lock_slowpath+0x13/0x15
> [ 2665.988300]  ? __mutex_lock_slowpath+0x13/0x15
> [ 2665.988301]  mutex_lock+0x2a/0x2d
> [ 2665.988304]  tty_lock+0x31/0x3c
> [ 2665.988306]  tty_release+0x48/0x53c
> [ 2665.988310]  __fput+0xf0/0x190
> [ 2665.988312]  ____fput+0xe/0x10
> [ 2665.988314]  task_work_run+0x79/0x8c
> [ 2665.988317]  do_exit+0x447/0x923
> [ 2665.988320]  ? recalc_sigpending_tsk+0x42/0x49
> [ 2665.988322]  do_group_exit+0x6c/0xa5
> [ 2665.988323]  get_signal+0x46b/0x4b3
> [ 2665.988327]  do_signal+0x37/0x5ed
> [ 2665.988329]  ? group_send_sig_info+0x4e/0x56
> [ 2665.988331]  ? SYSC_kill+0xa8/0x1b1
> [ 2665.988333]  ? do_sigaction+0xbe/0x18b
> [ 2665.988335]  ? __audit_syscall_entry+0xc2/0xe6
> [ 2665.988338]  prepare_exit_to_usermode+0x94/0xef
> [ 2665.988341]  syscall_return_slowpath+0xb9/0xd9
> [ 2665.988343]  do_fast_syscall_32+0xc3/0xfe
> [ 2665.988345]  entry_SYSENTER_compat+0x4c/0x5b
> [ 2665.988347] RIP: 0023:0xf7f24c29
> [ 2665.988348] RSP: 002b:00000000ffccf9ec EFLAGS: 00000206 ORIG_RAX: 0000000000000025
> [ 2665.988350] RAX: 0000000000000000 RBX: 0000000000001635 RCX: 0000000000000001
> [ 2665.988351] RDX: 0000000000000001 RSI: 00000000080a0310 RDI: 0000000000000000
> [ 2665.988351] RBP: 0000000000000001 R08: 0000000000000000 R09: 0000000000000000
> [ 2665.988352] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
> [ 2665.988353] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
> 
> Thanks,
> Marc
> -- 
> "A mouse is a device used to point at the xterm you want to type in" - A.S.R.
> Microsoft is to operating systems ....
>                                       .... what McDonalds is to gourmet cooking
> Home page: http://marc.merlins.org/                         | PGP 1024R/763BE901
> --
> To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html