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
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 >
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
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 >
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.