linux-btrfs.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* kernel trace, (nearly) every time on send/receive
@ 2019-11-26 22:27 Christoph Anton Mitterer
  2019-12-02  2:58 ` Anand Jain
  0 siblings, 1 reply; 5+ messages in thread
From: Christoph Anton Mitterer @ 2019-11-26 22:27 UTC (permalink / raw)
  To: Btrfs BTRFS

Hey.

Since ages (my report on bugzilla[0], where the problem existed however
for probably a year or even longer, is for 4.16.16), a call trace like
the following happens nearly every time I do a send/receive:


Nov 26 23:22:38 heisenberg kernel: ------------[ cut here ]------------
Nov 26 23:22:38 heisenberg kernel: WARNING: CPU: 2 PID: 7186 at fs/btrfs/send.c:6684 btrfs_ioctl_send.cold.57+0xc/0x13 [btrfs]
Nov 26 23:22:38 heisenberg kernel: Modules linked in: uas(E) xt_CHECKSUM(E) xt_MASQUERADE(E) nft_chain_nat(E) nf_nat(E) tun(E) bridge(E) stp(E) llc(E) ctr(E) ccm(E) fuse(E) cpufreq_userspace(E) cpufreq_powersave(E) cpufreq_conservative(E) snd_hda_codec_hdmi(E) intel_rapl(E) arc4(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) coretemp(E) snd_hda_codec_realtek(E) kvm_intel(E) snd_hda_codec_generic(E) hid_generic(E) ledtrig_audio(E) btusb(E) i2c_designware_platform(E) i2c_designware_core(E) btrtl(E) kvm(E) iTCO_wdt(E) btbcm(E) mei_wdt(E) btintel(E) iTCO_vendor_support(E) irqbypass(E) watchdog(E) bluetooth(E) intel_wmi_thunderbolt(E) snd_soc_skl(E) snd_soc_skl_ipc(E) snd_soc_sst_ipc(E) crct10dif_pclmul(E) snd_soc_sst_dsp(E) iwlmvm(E) snd_hda_ext_core(E) snd_soc_acpi_intel_match(E) snd_soc_acpi(E) snd_soc_core(E) crc32_pclmul(E) mac80211(E) uvcvideo(E) snd_compress(E) videobuf2_vmalloc(E) snd_usb_audio(E) drbg(E) videobuf2_memops(E) snd_hda_intel(E) i915(E) snd_usbmidi_lib(E) videobuf2_v4
 l2(E) ghash_clmulni_intel(E)
Nov 26 23:22:38 heisenberg kernel:  snd_rawmidi(E) intel_cstate(E) snd_seq_device(E) cdc_mbim(E) intel_uncore(E) sdhci_pci(E) snd_hda_codec(E) cdc_wdm(E) videobuf2_common(E) iwlwifi(E) snd_hda_core(E) cdc_ncm(E) intel_rapl_perf(E) snd_hwdep(E) ansi_cprng(E) pcspkr(E) cqhci(E) joydev(E) usbhid(E) videodev(E) snd_pcm(E) snd_timer(E) usbnet(E) drm_kms_helper(E) mii(E) hid(E) snd(E) sdhci(E) soundcore(E) cfg80211(E) sg(E) idma64(E) ecdh_generic(E) media(E) i2c_i801(E) ecc(E) mmc_core(E) rfkill(E) crc16(E) drm(E) intel_lpss_pci(E) mei_me(E) intel_lpss(E) mei(E) mfd_core(E) i2c_algo_bit(E) wmi(E) button(E) battery(E) xt_tcpudp(E) ip6t_REJECT(E) nf_reject_ipv6(E) pcc_cpufreq(E) tpm_crb(E) tpm_tis(E) fujitsu_laptop(E) tpm_tis_core(E) sparse_keymap(E) video(E) tpm(E) ac(E) acpi_pad(E) rng_core(E) nft_counter(E) xt_comment(E) ipt_REJECT(E) nf_reject_ipv4(E) xt_multiport(E) xt_policy(E) xt_state(E) xt_conntrack(E) nf_conntrack(E) nf_defrag_ipv6(E) nf_defrag_ipv4(E) nft_compat(E) nf_tables(E) nf
 netlink(E) binfmt_misc(E)
Nov 26 23:22:38 heisenberg kernel:  loop(E) parport_pc(E) ppdev(E) lp(E) parport(E) sunrpc(E) ip_tables(E) x_tables(E) autofs4(E) dm_crypt(E) dm_mod(E) raid10(E) raid456(E) async_raid6_recov(E) async_memcpy(E) async_pq(E) async_xor(E) async_tx(E) raid1(E) raid0(E) multipath(E) linear(E) md_mod(E) btrfs(E) libcrc32c(E) crc32c_generic(E) xor(E) zstd_decompress(E) zstd_compress(E) raid6_pq(E) uhci_hcd(E) ehci_pci(E) ehci_hcd(E) usb_storage(E) sd_mod(E) crc32c_intel(E) aesni_intel(E) xhci_pci(E) xhci_hcd(E) evdev(E) ahci(E) aes_x86_64(E) libahci(E) glue_helper(E) crypto_simd(E) psmouse(E) cryptd(E) serio_raw(E) e1000e(E) libata(E) ptp(E) pps_core(E) usbcore(E) scsi_mod(E) usb_common(E)
Nov 26 23:22:38 heisenberg kernel: CPU: 2 PID: 7186 Comm: btrfs Tainted: G            E     5.2.0-3-amd64 #1 Debian 5.2.17-1
Nov 26 23:22:38 heisenberg kernel: Hardware name: FUJITSU LIFEBOOK U757/FJNB2A5, BIOS Version 1.21 03/19/2018
Nov 26 23:22:38 heisenberg kernel: RIP: 0010:btrfs_ioctl_send.cold.57+0xc/0x13 [btrfs]
Nov 26 23:22:38 heisenberg kernel: Code: fe ff 48 c7 c2 dd 23 48 c0 89 de 4c 89 ff 41 be fb ff ff ff e8 16 fe ff ff e9 88 cf fe ff 48 c7 c7 88 a1 48 c0 e8 09 4b 87 d0 <0f> 0b e9 41 dd fe ff 0f 1f 44 00 00 55 53 48 89 fb 48 83 ec 30 65
Nov 26 23:22:38 heisenberg kernel: RSP: 0018:ffffbb4c8b653c08 EFLAGS: 00010246
Nov 26 23:22:38 heisenberg kernel: RAX: 0000000000000024 RBX: ffff9ba937a0b3f4 RCX: 0000000000000000
Nov 26 23:22:38 heisenberg kernel: RDX: 0000000000000000 RSI: ffff9ba93db17688 RDI: ffff9ba93db17688
Nov 26 23:22:38 heisenberg kernel: RBP: ffff9ba2c6c58840 R08: 00000000000003df R09: 0000000000000033
Nov 26 23:22:38 heisenberg kernel: R10: 0000000000000000 R11: ffffbb4c8b653ab8 R12: ffff9ba8f9b0f100
Nov 26 23:22:38 heisenberg kernel: R13: ffff9ba937a0b000 R14: 00007ffc5a31b230 R15: ffff9ba7c7edc000
Nov 26 23:22:38 heisenberg kernel: FS:  00007ff9744fc8c0(0000) GS:ffff9ba93db00000(0000) knlGS:0000000000000000
Nov 26 23:22:38 heisenberg kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Nov 26 23:22:38 heisenberg kernel: CR2: 00007ff9744fae38 CR3: 00000005b9106005 CR4: 00000000003606e0
Nov 26 23:22:38 heisenberg kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Nov 26 23:22:38 heisenberg kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Nov 26 23:22:38 heisenberg kernel: Call Trace:
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? syscall_return_via_sysret+0x10/0x7f
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
Nov 26 23:22:38 heisenberg kernel:  ? _cond_resched+0x15/0x30
Nov 26 23:22:38 heisenberg kernel:  ? __kmalloc_track_caller+0x160/0x200
Nov 26 23:22:38 heisenberg kernel:  ? _btrfs_ioctl_send+0xf6/0x110 [btrfs]
Nov 26 23:22:38 heisenberg kernel:  ? __check_object_size+0x162/0x173
Nov 26 23:22:38 heisenberg kernel:  _btrfs_ioctl_send+0xdd/0x110 [btrfs]
Nov 26 23:22:38 heisenberg kernel:  ? task_rq_lock+0x49/0xb0
Nov 26 23:22:38 heisenberg kernel:  ? tomoyo_init_request_info+0x84/0x90
Nov 26 23:22:38 heisenberg kernel:  btrfs_ioctl+0xd47/0x2dc0 [btrfs]
Nov 26 23:22:38 heisenberg kernel:  ? do_vfs_ioctl+0xa4/0x630
Nov 26 23:22:38 heisenberg kernel:  do_vfs_ioctl+0xa4/0x630
Nov 26 23:22:38 heisenberg kernel:  ksys_ioctl+0x60/0x90
Nov 26 23:22:38 heisenberg kernel:  __x64_sys_ioctl+0x16/0x20
Nov 26 23:22:38 heisenberg kernel:  do_syscall_64+0x53/0x130
Nov 26 23:22:38 heisenberg kernel:  entry_SYSCALL_64_after_hwframe+0x44/0xa9
Nov 26 23:22:38 heisenberg kernel: RIP: 0033:0x7ff9745f05b7
Nov 26 23:22:38 heisenberg kernel: Code: 00 00 90 48 8b 05 d9 78 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a9 78 0c 00 f7 d8 64 89 01 48
Nov 26 23:22:38 heisenberg kernel: RSP: 002b:00007ffc5a31b168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
Nov 26 23:22:38 heisenberg kernel: RAX: ffffffffffffffda RBX: 0000000000003765 RCX: 00007ff9745f05b7
Nov 26 23:22:38 heisenberg kernel: RDX: 00007ffc5a31b230 RSI: 0000000040489426 RDI: 0000000000000004
Nov 26 23:22:38 heisenberg kernel: RBP: 0000000000000004 R08: 0000000000000000 R09: 00007ff9744fb700
Nov 26 23:22:38 heisenberg kernel: R10: 00007ff9744fb9d0 R11: 0000000000000246 R12: 0000000000000001
Nov 26 23:22:38 heisenberg kernel: R13: 0000000000000001 R14: 0000000000000000 R15: 0000557b6f392270
Nov 26 23:22:38 heisenberg kernel: ---[ end trace 9482d6e062565866 ]---


Any chance to get that ever fixed? Any further data or so that would
help?


Thanks,
Chris.


[0] https://bugzilla.kernel.org/show_bug.cgi?id=200255


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: kernel trace, (nearly) every time on send/receive
  2019-11-26 22:27 kernel trace, (nearly) every time on send/receive Christoph Anton Mitterer
@ 2019-12-02  2:58 ` Anand Jain
  2019-12-02  3:30   ` Christoph Anton Mitterer
  0 siblings, 1 reply; 5+ messages in thread
From: Anand Jain @ 2019-12-02  2:58 UTC (permalink / raw)
  To: Christoph Anton Mitterer, Btrfs BTRFS

On 27/11/19 6:27 AM, Christoph Anton Mitterer wrote:
> Hey.
> 
> Since ages (my report on bugzilla[0], where the problem existed however
> for probably a year or even longer, is for 4.16.16), a call trace like
> the following happens nearly every time I do a send/receive:
> 
> 
> Nov 26 23:22:38 heisenberg kernel: ------------[ cut here ]------------
> Nov 26 23:22:38 heisenberg kernel: WARNING: CPU: 2 PID: 7186 at fs/btrfs/send.c:6684 btrfs_ioctl_send.cold.57+0xc/0x13 [btrfs]


Looks like ORPHAN_CLEANUP_DONE is not set on the root.

         WARN_ON(send_root->orphan_cleanup_state != ORPHAN_CLEANUP_DONE);

ORPHAN_CLEANUP_DONE is set unless it is a readonly FS, which I doubt is,
(can be checked using btrfs inspect duper-super <dev>) because you are
creating the snapshot for the send. btrfs check --readonly might tell
us more about the issue.

Thanks, Anand


> Nov 26 23:22:38 heisenberg kernel: Modules linked in: uas(E) xt_CHECKSUM(E) xt_MASQUERADE(E) nft_chain_nat(E) nf_nat(E) tun(E) bridge(E) stp(E) llc(E) ctr(E) ccm(E) fuse(E) cpufreq_userspace(E) cpufreq_powersave(E) cpufreq_conservative(E) snd_hda_codec_hdmi(E) intel_rapl(E) arc4(E) x86_pkg_temp_thermal(E) intel_powerclamp(E) coretemp(E) snd_hda_codec_realtek(E) kvm_intel(E) snd_hda_codec_generic(E) hid_generic(E) ledtrig_audio(E) btusb(E) i2c_designware_platform(E) i2c_designware_core(E) btrtl(E) kvm(E) iTCO_wdt(E) btbcm(E) mei_wdt(E) btintel(E) iTCO_vendor_support(E) irqbypass(E) watchdog(E) bluetooth(E) intel_wmi_thunderbolt(E) snd_soc_skl(E) snd_soc_skl_ipc(E) snd_soc_sst_ipc(E) crct10dif_pclmul(E) snd_soc_sst_dsp(E) iwlmvm(E) snd_hda_ext_core(E) snd_soc_acpi_intel_match(E) snd_soc_acpi(E) snd_soc_core(E) crc32_pclmul(E) mac80211(E) uvcvideo(E) snd_compress(E) videobuf2_vmalloc(E) snd_usb_audio(E) drbg(E) videobuf2_memops(E) snd_hda_intel(E) i915(E) snd_usbmidi_lib(E) videobuf2_v4
>   l2(E) ghash_clmulni_intel(E)
> Nov 26 23:22:38 heisenberg kernel:  snd_rawmidi(E) intel_cstate(E) snd_seq_device(E) cdc_mbim(E) intel_uncore(E) sdhci_pci(E) snd_hda_codec(E) cdc_wdm(E) videobuf2_common(E) iwlwifi(E) snd_hda_core(E) cdc_ncm(E) intel_rapl_perf(E) snd_hwdep(E) ansi_cprng(E) pcspkr(E) cqhci(E) joydev(E) usbhid(E) videodev(E) snd_pcm(E) snd_timer(E) usbnet(E) drm_kms_helper(E) mii(E) hid(E) snd(E) sdhci(E) soundcore(E) cfg80211(E) sg(E) idma64(E) ecdh_generic(E) media(E) i2c_i801(E) ecc(E) mmc_core(E) rfkill(E) crc16(E) drm(E) intel_lpss_pci(E) mei_me(E) intel_lpss(E) mei(E) mfd_core(E) i2c_algo_bit(E) wmi(E) button(E) battery(E) xt_tcpudp(E) ip6t_REJECT(E) nf_reject_ipv6(E) pcc_cpufreq(E) tpm_crb(E) tpm_tis(E) fujitsu_laptop(E) tpm_tis_core(E) sparse_keymap(E) video(E) tpm(E) ac(E) acpi_pad(E) rng_core(E) nft_counter(E) xt_comment(E) ipt_REJECT(E) nf_reject_ipv4(E) xt_multiport(E) xt_policy(E) xt_state(E) xt_conntrack(E) nf_conntrack(E) nf_defrag_ipv6(E) nf_defrag_ipv4(E) nft_compat(E) nf_tables(E) nf
>   netlink(E) binfmt_misc(E)
> Nov 26 23:22:38 heisenberg kernel:  loop(E) parport_pc(E) ppdev(E) lp(E) parport(E) sunrpc(E) ip_tables(E) x_tables(E) autofs4(E) dm_crypt(E) dm_mod(E) raid10(E) raid456(E) async_raid6_recov(E) async_memcpy(E) async_pq(E) async_xor(E) async_tx(E) raid1(E) raid0(E) multipath(E) linear(E) md_mod(E) btrfs(E) libcrc32c(E) crc32c_generic(E) xor(E) zstd_decompress(E) zstd_compress(E) raid6_pq(E) uhci_hcd(E) ehci_pci(E) ehci_hcd(E) usb_storage(E) sd_mod(E) crc32c_intel(E) aesni_intel(E) xhci_pci(E) xhci_hcd(E) evdev(E) ahci(E) aes_x86_64(E) libahci(E) glue_helper(E) crypto_simd(E) psmouse(E) cryptd(E) serio_raw(E) e1000e(E) libata(E) ptp(E) pps_core(E) usbcore(E) scsi_mod(E) usb_common(E)
> Nov 26 23:22:38 heisenberg kernel: CPU: 2 PID: 7186 Comm: btrfs Tainted: G            E     5.2.0-3-amd64 #1 Debian 5.2.17-1
> Nov 26 23:22:38 heisenberg kernel: Hardware name: FUJITSU LIFEBOOK U757/FJNB2A5, BIOS Version 1.21 03/19/2018
> Nov 26 23:22:38 heisenberg kernel: RIP: 0010:btrfs_ioctl_send.cold.57+0xc/0x13 [btrfs]
> Nov 26 23:22:38 heisenberg kernel: Code: fe ff 48 c7 c2 dd 23 48 c0 89 de 4c 89 ff 41 be fb ff ff ff e8 16 fe ff ff e9 88 cf fe ff 48 c7 c7 88 a1 48 c0 e8 09 4b 87 d0 <0f> 0b e9 41 dd fe ff 0f 1f 44 00 00 55 53 48 89 fb 48 83 ec 30 65
> Nov 26 23:22:38 heisenberg kernel: RSP: 0018:ffffbb4c8b653c08 EFLAGS: 00010246
> Nov 26 23:22:38 heisenberg kernel: RAX: 0000000000000024 RBX: ffff9ba937a0b3f4 RCX: 0000000000000000
> Nov 26 23:22:38 heisenberg kernel: RDX: 0000000000000000 RSI: ffff9ba93db17688 RDI: ffff9ba93db17688
> Nov 26 23:22:38 heisenberg kernel: RBP: ffff9ba2c6c58840 R08: 00000000000003df R09: 0000000000000033
> Nov 26 23:22:38 heisenberg kernel: R10: 0000000000000000 R11: ffffbb4c8b653ab8 R12: ffff9ba8f9b0f100
> Nov 26 23:22:38 heisenberg kernel: R13: ffff9ba937a0b000 R14: 00007ffc5a31b230 R15: ffff9ba7c7edc000
> Nov 26 23:22:38 heisenberg kernel: FS:  00007ff9744fc8c0(0000) GS:ffff9ba93db00000(0000) knlGS:0000000000000000
> Nov 26 23:22:38 heisenberg kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> Nov 26 23:22:38 heisenberg kernel: CR2: 00007ff9744fae38 CR3: 00000005b9106005 CR4: 00000000003606e0
> Nov 26 23:22:38 heisenberg kernel: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> Nov 26 23:22:38 heisenberg kernel: DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
> Nov 26 23:22:38 heisenberg kernel: Call Trace:
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? syscall_return_via_sysret+0x10/0x7f
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x40/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? __switch_to_asm+0x34/0x70
> Nov 26 23:22:38 heisenberg kernel:  ? _cond_resched+0x15/0x30
> Nov 26 23:22:38 heisenberg kernel:  ? __kmalloc_track_caller+0x160/0x200
> Nov 26 23:22:38 heisenberg kernel:  ? _btrfs_ioctl_send+0xf6/0x110 [btrfs]
> Nov 26 23:22:38 heisenberg kernel:  ? __check_object_size+0x162/0x173
> Nov 26 23:22:38 heisenberg kernel:  _btrfs_ioctl_send+0xdd/0x110 [btrfs]
> Nov 26 23:22:38 heisenberg kernel:  ? task_rq_lock+0x49/0xb0
> Nov 26 23:22:38 heisenberg kernel:  ? tomoyo_init_request_info+0x84/0x90
> Nov 26 23:22:38 heisenberg kernel:  btrfs_ioctl+0xd47/0x2dc0 [btrfs]
> Nov 26 23:22:38 heisenberg kernel:  ? do_vfs_ioctl+0xa4/0x630
> Nov 26 23:22:38 heisenberg kernel:  do_vfs_ioctl+0xa4/0x630
> Nov 26 23:22:38 heisenberg kernel:  ksys_ioctl+0x60/0x90
> Nov 26 23:22:38 heisenberg kernel:  __x64_sys_ioctl+0x16/0x20
> Nov 26 23:22:38 heisenberg kernel:  do_syscall_64+0x53/0x130
> Nov 26 23:22:38 heisenberg kernel:  entry_SYSCALL_64_after_hwframe+0x44/0xa9
> Nov 26 23:22:38 heisenberg kernel: RIP: 0033:0x7ff9745f05b7
> Nov 26 23:22:38 heisenberg kernel: Code: 00 00 90 48 8b 05 d9 78 0c 00 64 c7 00 26 00 00 00 48 c7 c0 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 b8 10 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d a9 78 0c 00 f7 d8 64 89 01 48
> Nov 26 23:22:38 heisenberg kernel: RSP: 002b:00007ffc5a31b168 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
> Nov 26 23:22:38 heisenberg kernel: RAX: ffffffffffffffda RBX: 0000000000003765 RCX: 00007ff9745f05b7
> Nov 26 23:22:38 heisenberg kernel: RDX: 00007ffc5a31b230 RSI: 0000000040489426 RDI: 0000000000000004
> Nov 26 23:22:38 heisenberg kernel: RBP: 0000000000000004 R08: 0000000000000000 R09: 00007ff9744fb700
> Nov 26 23:22:38 heisenberg kernel: R10: 00007ff9744fb9d0 R11: 0000000000000246 R12: 0000000000000001
> Nov 26 23:22:38 heisenberg kernel: R13: 0000000000000001 R14: 0000000000000000 R15: 0000557b6f392270
> Nov 26 23:22:38 heisenberg kernel: ---[ end trace 9482d6e062565866 ]---
> 
> 
> Any chance to get that ever fixed? Any further data or so that would
> help?
> 
> 
> Thanks,
> Chris.
> 
> 
> [0] https://bugzilla.kernel.org/show_bug.cgi?id=200255
> 


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: kernel trace, (nearly) every time on send/receive
  2019-12-02  2:58 ` Anand Jain
@ 2019-12-02  3:30   ` Christoph Anton Mitterer
  2019-12-02  4:37     ` Anand Jain
  0 siblings, 1 reply; 5+ messages in thread
From: Christoph Anton Mitterer @ 2019-12-02  3:30 UTC (permalink / raw)
  To: Anand Jain, Btrfs BTRFS

Hey Anand.

Thanks for looking into this.

On Mon, 2019-12-02 at 10:58 +0800, Anand Jain wrote:
> Looks like ORPHAN_CLEANUP_DONE is not set on the root.
> 
>          WARN_ON(send_root->orphan_cleanup_state !=
> ORPHAN_CLEANUP_DONE);
> 
> ORPHAN_CLEANUP_DONE is set unless it is a readonly FS, which I doubt
> is,
> (can be checked using btrfs inspect duper-super <dev>) because you
> are
> creating the snapshot for the send.

I should perhaps add, that there are two btrfs filesystems involved
here:
The first is basically the master, having several snapshots including
all + one newer which is missing from the second (which is basically a
backup of the master).

So it's about:
/master# btrfs send -p already-on-copy newer-snapshot | btrfs receive /copy/snapshots/ ; 

In fact /master is mounted ro only here, whereas /copy is of course
mounted rw.
Since nothing should be changed on /master I assumed it would be ok to
have it mounted ro.


>  btrfs check --readonly might tell
> us more about the issue.

I cannot do this right now since I'll be on some diving vacation for ~2
weeks,... but since --readonly is the standard behaviour (i.e. same
without --readonly) I'm pretty sure that a fsck (which I always do
after each snapshot to the /copy) brought now visible errors.


Does the whole thing imply any corruption to any of the two
filesystems... or is it just a "cosmetic" issue?


Cheers,
Chris


^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: kernel trace, (nearly) every time on send/receive
  2019-12-02  3:30   ` Christoph Anton Mitterer
@ 2019-12-02  4:37     ` Anand Jain
  2019-12-02 13:04       ` Christoph Anton Mitterer
  0 siblings, 1 reply; 5+ messages in thread
From: Anand Jain @ 2019-12-02  4:37 UTC (permalink / raw)
  To: Christoph Anton Mitterer, Btrfs BTRFS



On 2/12/19 11:30 AM, Christoph Anton Mitterer wrote:
> Hey Anand.
> 
> Thanks for looking into this.
> 
> On Mon, 2019-12-02 at 10:58 +0800, Anand Jain wrote:
>> Looks like ORPHAN_CLEANUP_DONE is not set on the root.
>>
>>           WARN_ON(send_root->orphan_cleanup_state !=
>> ORPHAN_CLEANUP_DONE);
>>
>> ORPHAN_CLEANUP_DONE is set unless it is a readonly FS, which I doubt
>> is,
>> (can be checked using btrfs inspect duper-super <dev>) because you
>> are
>> creating the snapshot for the send.
> 
> I should perhaps add, that there are two btrfs filesystems involved
> here:
> The first is basically the master, having several snapshots including
> all + one newer which is missing from the second (which is basically a
> backup of the master).
> 
> So it's about:
> /master# btrfs send -p already-on-copy newer-snapshot | btrfs receive /copy/snapshots/ ;
> 
> In fact /master is mounted ro only here, whereas /copy is of course
> mounted rw.
> Since nothing should be changed on /master I assumed it would be ok to
> have it mounted ro.
> 

  I am able to reproduce. Create send from the readonly mounted FS
  and we log the warning as we couldn't clean the orphan flag. It's
  false positive log. Will fix.

  As of now there is nothing that tells me the FS at your end would
  need a btrfs check so please ignore that part.

  One question though - why the FS is readonly mounted? Its ok if that's
  part of your operations.

Thanks, Anand


>>   btrfs check --readonly might tell
>> us more about the issue.
> 
> I cannot do this right now since I'll be on some diving vacation for ~2
> weeks,... but since --readonly is the standard behaviour (i.e. same
> without --readonly) I'm pretty sure that a fsck (which I always do
> after each snapshot to the /copy) brought now visible errors.
> 
> 
> Does the whole thing imply any corruption to any of the two
> filesystems... or is it just a "cosmetic" issue?
> 
> 
> Cheers,
> Chris
> 

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: kernel trace, (nearly) every time on send/receive
  2019-12-02  4:37     ` Anand Jain
@ 2019-12-02 13:04       ` Christoph Anton Mitterer
  0 siblings, 0 replies; 5+ messages in thread
From: Christoph Anton Mitterer @ 2019-12-02 13:04 UTC (permalink / raw)
  To: Anand Jain, Btrfs BTRFS

Hey.


On Mon, 2019-12-02 at 12:37 +0800, Anand Jain wrote:
>   I am able to reproduce. Create send from the readonly mounted FS
>   and we log the warning as we couldn't clean the orphan flag. It's
>   false positive log. Will fix.

Great, thanks! :-)


>   One question though - why the FS is readonly mounted? Its ok if
> that's
>   part of your operations.

It's effectively just part of my opterations. The HDD is an mostly an
archival storage where I put photos/etc. on.
fstab entries are, that it's mounted per default ro (so I cannot
accidentally delete something or so), and this is why I do the
send/receive from an ro-mounted fs.

Cheers,
Chris.


^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2019-12-02 13:04 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-11-26 22:27 kernel trace, (nearly) every time on send/receive Christoph Anton Mitterer
2019-12-02  2:58 ` Anand Jain
2019-12-02  3:30   ` Christoph Anton Mitterer
2019-12-02  4:37     ` Anand Jain
2019-12-02 13:04       ` Christoph Anton Mitterer

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).