Description: Inside VM, rsync bails out with guest-VM-kernel trace when folder is rsynced form a ntfs3-fs to ext4-fs. Steps to reproduce 1) prepare virtual disks 2) boot livecd in qemu 3) create partition on sda, and put filesystem on sda1 4) mkdir -p /mnt/a /mnt/b 5) mount -t ext4 /dev/sda1 /mnt/a 6) mount -t ntfs3 /dev/sdb2 /mnt/b 7) (sdate=`date` ; cd /mnt/b ; rsync -avH ./photos001 /mnt/a | tee /tmp/rst.txt ; echo $sdate; date ) HOST * OS: fedora-35 * kernel: have tried 5.10.90 (self-built) -> 5.15.13 (from koji https://koji.fedoraproject.org/koji/packageinfo?packageID=8) * qemu: 6.2.0-1.fc36.x86_64 (from koji https://koji.fedoraproject.org/koji/packageinfo?packageID=685) GUEST * guest kernel: > 5.15.4 (as ntfs3 kernel driver must exist) Livecd: * archlinux-2022.01.01-x86_64.iso (kernel-5.15.12) * manjaro-gnome-21.2.0-211220-linux515.iso (kernel-5.15.7) * ( Fedora-Workstation-Live-x86_64-Rawhide-20220104.n.0.iso also bails out but with different kernel trace, as it is on 5.16.0-rc8 kernel, perhaps due to more changes in io_uring, nvmem, folio ) virtual-disk1 (sda): * qcow2/vhdx/raw * fresh/blank, partition and filesystem created after booting livecd * qemu-img create -f qcow2 -o preallocation=falloc /mnt/a16/gkpics01.qcow2 99723771904 * located on an exfat partition virtual-disk2 (sdb): * vhdx with ntfs3 containing synthetic data generated as per script-lets included in comment in issue 727 filed against qemu * https://gitlab.com/qemu-project/qemu/-/issues/727#note_739930694 * located on an ntfs3 partition QEMU invocation: [root@sirius gana]# qemu-system-x86_64 -cpu qemu64 -m 4096 -machine "type=q35" -accel "kvm" -smp "sockets=1,cores=8,threads=1" -boot "d" -cdrom "/vol/15KJ_Images/transcend/archlinux-2022.01.01-x86_64.iso" -hda "/mnt/a16/gkpics01.raw" -hdb "/vol/15KJ_Images/test/sgdata.vhdx" -device "virtio-vga" -display "gtk,gl=on" -rtc "base=utc" -net "user" -device "virtio-net,netdev=vmnic" -netdev "user,id=vmnic,net=192.168.20.0/24,dns=192.168.20.3,dhcpstart=192.168.20.15" Observations * bug happens regardless of what type of virtualdisk sda1 is qcow2/vhdx/raw. Also does not matter if virtual-disk is fixed/dynamic. If dynamic, one may enounter other bugs from qemu (issue 727), so for these tests am using fixed * bug does not happen when src-fs/folder is /usr from livecd * bug happens when src-fs is ntfs3 and dst-fs is ext4 or ntfs3 The kernel trace: [ 557.606589] BUG: unable to handle page fault for address: ffffffa526d7d5ff [ 557.606721] #PF: supervisor instruction fetch in kernel mode [ 557.606794] #PF: error_code(0x0010) - not-present page [ 557.606877] PGD 64215067 P4D 64215067 PUD 0 [ 557.607032] Oops: 0010 [#1] PREEMPT SMP PTI [ 557.607189] CPU: 5 PID: 965 Comm: rsync Not tainted 5.15.12-arch1-1 #1 eeb185e1d4b23217f1216641b0351a46bd23d8bc [ 557.607579] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1.fc35 04/01/2014 [ 557.608017] RIP: 0010:0xffffffa526d7d5ff [ 557.608183] Code: Unable to access opcode bytes at RIP 0xffffffa526d7d5d5. [ 557.608392] RSP: 0018:ffffb15540df7b47 EFLAGS: 00010246 [ 557.608594] RAX: 0000000000000000 RBX: 00000000000011ca RCX: 0000000000000000 [ 557.608803] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 557.609001] RBP: ffb15540df7c3000 R08: 0000000000000000 R09: 0000000000000000 [ 557.609202] R10: 0000000000000000 R11: 0000000000000000 R12: ffa0e40fb7524800 [ 557.609442] R13: 00000001112ccaff R14: ffe941c1b2120000 R15: 00000000000030ff [ 557.609682] FS: 00007f37d09c3580(0000) GS:ffffa0e43bd40000(0000) knlGS:0000000000000000 [ 557.610127] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 557.610400] CR2: ffffffa526d7d5d5 CR3: 000000010611e000 CR4: 00000000000006e0 [ 557.610671] Call Trace: [ 557.610918] <TASK> [ 557.611181] BUG: unable to handle page fault for address: ffffb15540df8000 [ 557.611513] #PF: supervisor read access in kernel mode [ 557.611788] #PF: error_code(0x0000) - not-present page [ 557.612070] PGD 100000067 P4D 100000067 PUD 1001c3067 PMD 100b36067 PTE 0 [ 557.612530] Oops: 0000 [#2] PREEMPT SMP PTI [ 557.613311] CPU: 5 PID: 965 Comm: rsync Not tainted 5.15.12-arch1-1 #1 eeb185e1d4b23217f1216641b0351a46bd23d8bc [ 557.614447] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1.fc35 04/01/2014 [ 557.615295] RIP: 0010:show_trace_log_lvl+0x1a4/0x32d [ 557.615640] Code: c7 34 65 45 a6 e8 0d be 00 00 4d 85 ed 74 41 0f b6 95 37 ff ff ff 4c 89 f1 4c 89 ee 48 8d bd 50 ff ff ff e8 dc fd ff ff eb 26 <4c> 8b 3b 48 8d bd 70 ff ff ff e8 2e 3e 52 ff 4c 89 ff 48 89 85 28 [ 557.616981] RSP: 0018:ffffb15540df78d8 EFLAGS: 00010012 [ 557.617456] RAX: 0000000000000000 RBX: ffffb15540df7fff RCX: 0000000000000000 [ 557.618486] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 557.619200] RBP: ffffb15540df79b8 R08: 0000000000000000 R09: 0000000000000000 [ 557.619663] R10: 0000000000000000 R11: 0000000000000000 R12: ffffa0e3d9b51e80 [ 557.620173] R13: 0000000000000000 R14: ffffffffa647d7ef R15: 0000000000002b00 [ 557.620617] FS: 00007f37d09c3580(0000) GS:ffffa0e43bd40000(0000) knlGS:0000000000000000 [ 557.622079] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 557.622830] CR2: ffffb15540df8000 CR3: 000000010611e000 CR4: 00000000000006e0 [ 557.623804] Call Trace: [ 557.624533] <TASK> [ 557.624973] __die_body.cold+0x1a/0x1f [ 557.625417] page_fault_oops+0x19e/0x310 [ 557.625830] exc_page_fault+0xda/0x180 [ 557.626231] asm_exc_page_fault+0x1e/0x30 [ 557.626601] RIP: 0010:0xffffffa526d7d5ff [ 557.626914] Code: Unable to access opcode bytes at RIP 0xffffffa526d7d5d5. [ 557.627227] RSP: 0018:ffffb15540df7b47 EFLAGS: 00010246 [ 557.627578] RAX: 0000000000000000 RBX: 00000000000011ca RCX: 0000000000000000 [ 557.627912] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 557.628222] RBP: ffb15540df7c3000 R08: 0000000000000000 R09: 0000000000000000 [ 557.628538] R10: 0000000000000000 R11: 0000000000000000 R12: ffa0e40fb7524800 [ 557.628835] R13: 00000001112ccaff R14: ffe941c1b2120000 R15: 00000000000030ff [ 557.629129] ? page_cache_ra_unbounded+0x1c5/0x250 [ 557.629425] ? filemap_get_pages+0x269/0x730 [ 557.629708] ? filemap_read+0xb9/0x360 [ 557.630041] ? new_sync_read+0x159/0x1f0 [ 557.630373] ? vfs_read+0xff/0x1a0 [ 557.630646] ? ksys_read+0x67/0xf0 [ 557.630918] ? do_syscall_64+0x5c/0x90 [ 557.631159] ? syscall_exit_to_user_mode+0x23/0x50 [ 557.631413] ? do_syscall_64+0x69/0x90 [ 557.631658] ? syscall_exit_to_user_mode+0x23/0x50 [ 557.631905] ? do_syscall_64+0x69/0x90 [ 557.632148] ? do_syscall_64+0x69/0x90 [ 557.632388] ? syscall_exit_to_user_mode+0x23/0x50 [ 557.632617] ? do_syscall_64+0x69/0x90 [ 557.632838] ? do_syscall_64+0x69/0x90 [ 557.633048] ? do_syscall_64+0x69/0x90 [ 557.633248] ? entry_SYSCALL_64_after_hwframe+0x44/0xae [ 557.633465] </TASK> [ 557.633667] Modules linked in: ntfs3 ext4 crc32c_generic crc16 mbcache jbd2 qrtr ns ghash_generic gf128mul cryptd gcm ccm algif_aead des_generic libdes cbc ecb algif_skcipher cmac md4 algif_hash af_alg iTCO_wdt joydev pktcdvd intel_pmc_bxt mousedev i2c_i801 iTCO_vendor_support ppdev psmouse i2c_smbus parport_pc lpc_ich parport pcspkr mac_hid qemu_fw_cfg cfg80211 rfkill pkcs8_key_parser fuse bpf_preload ip_tables x_tables overlay squashfs loop isofs virtio_net net_failoverserio_raw virtio_gpu failover atkbd virtio_dma_buf libps2 i8042 virtio_pci intel_agp sr_mod cdrom intel_gtt virtio_pci_modern_dev serio [ 557.635756] CR2: ffffb15540df8000 [ 557.636059] ---[ end trace bf5039f09aa9ee49 ]--- [ 557.636381] RIP: 0010:0xffffffa526d7d5ff [ 557.636638] Code: Unable to access opcode bytes at RIP 0xffffffa526d7d5d5. [ 557.636896] RSP: 0018:ffffb15540df7b47 EFLAGS: 00010246 [ 557.637156] RAX: 0000000000000000 RBX: 00000000000011ca RCX: 0000000000000000 [ 557.637467] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 557.637736] RBP: ffb15540df7c3000 R08: 0000000000000000 R09: 0000000000000000 [ 557.638004] R10: 0000000000000000 R11: 0000000000000000 R12: ffa0e40fb7524800 [ 557.638297] R13: 00000001112ccaff R14: ffe941c1b2120000 R15: 00000000000030ff [ 557.638584] FS: 00007f37d09c3580(0000) GS:ffffa0e43bd40000(0000) knlGS:0000000000000000 [ 557.639135] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 557.639464] CR2: ffffffa526d7d5d5 CR3: 000000010611e000 CR4: 00000000000006e0 References * https://lore.kernel.org/all/Ycu2MGt%2FraXJ+wCb@casper.infradead.org/t/#u * https://lore.kernel.org/all/DM6PR04MB493813D5A09B3F03378E9398DA469@DM6PR04MB4938.namprd04.prod.outlook.com/ * https://gitlab.com/qemu-project/qemu/-/issues/727
- There was no guestVM-kernel-traceback and corruption did **not** happen on Win10-21H2-19044-1415/WHPX/ExFAT/VM-qemu-6.2.0/Fedora-Workstation-Live-x86_64-Rawhide-20220111.n.1.iso/kernel-5.16.0-60/**raw**/ext4 with sgdata on ntfs3/vhdx. I hope this is not a one-time chance success, and will not regress with newer kernel versions. I will recheck this under linux-kvm later. If indeed it is fixed, then *) What patch-fixes fixed it? *) Those patch-fixes to be back-ported and arrive on some later version of 5.15.x *) Monitor the situation and check if successive kernels show this bug.
While on windows, I tried several linux guest-VMs * A few Fedora Rawhide Live-cds going back to Fedora-Workstation-Live-Rawhide-20211206.n.0 (kernel=5.16-rc3) https://koji.fedoraproject.org/koji/packageinfo?packageID=22087 . None of them had a traceback or corruption * archlinux-2022.01.01-x86_64.iso (kernel-5.15.12) did not have traceback/corruption * manjaro-gnome-21.2.0-211220-linux515.iso (kernel-5.15.7) did have a traceback/rync-bailout. Unlike in linux, wherein rsync bails out pretty soon after starting rsync, in windows, the rsync bailout happened after going through around 80% of the sgdata. * rsyncing the full-sgdata takes around 15 min in linux 20 min in windows. Probably, Perhaps, * this issue is transfer speed dependent * machine speed and host-OS-IO-performance matter. I am on haswell i7-4700mq. vdisk1 on SDD, vdisk2 on HDD. * The speed of file-operations matter. Windows is an file-operation-inefficient OS compared to linux. So the slowness of the host-OS is making it easy for Qemu/Guest. * If it is a non-ntfs3 kernel bug, located in kernel-block/io code, its chances of reproduction reduce, if with time, the kernel-io code quality improves * This could be a qemu bug, if it happens only inside qemu. * The issue may happen on windows on the other images, if the data set is large enough to run longer, requiring some chance event to occur. TRACEBACK on windows: dmesg Traceback under manjaro-gnome-21.2.0-211220-linux515.iso (kernel-5.15.7) [ 1069.271027] BUG: unable to handle page fault for address: ffffffade6d985ff [ 1069.271038] #PF: supervisor instruction fetch in kernel mode [ 1069.271041] #PF: error_code(0x0010) - not-present page [ 1069.271044] PGD 17b815067 P4D 17b815067 PUD 0 [ 1069.271051] Oops: 0010 [#1] PREEMPT SMP PTI [ 1069.271055] CPU: 1 PID: 4994 Comm: rsync Tainted: P OE 5.15.7-1-MANJARO #1 89d91431fe07b9fd339e5f86d7a009210c48fcc6 [ 1069.271061] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014 [ 1069.271064] RIP: 0010:0xffffffade6d985ff [ 1069.271071] Code: Unable to access opcode bytes at RIP 0xffffffade6d985d5. [ 1069.271073] RSP: 0018:ffffbd6ec27e3b6f EFLAGS: 00010246 [ 1069.271077] RAX: 0000000000000000 RBX: 0000000000001800 RCX: 0000000000000000 [ 1069.271080] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 1069.271082] RBP: ffbd6ec27e3c5800 R08: 0000000000000000 R09: 0000000000000000 [ 1069.271085] R10: 0000000000000000 R11: 0000000000000000 R12: ff93f3834e26a000 [ 1069.271087] R13: 00000001112ccaff R14: ffdddbc51946c000 R15: 00000000000277ff [ 1069.271090] FS: 00007f0b6f840580(0000) GS:ffff93f3ffc40000(0000) knlGS:0000000000000000 [ 1069.271094] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1069.271096] CR2: ffffffade6d985d5 CR3: 000000000dfb0000 CR4: 00000000001106e0 [ 1069.271102] Call Trace: [ 1069.271128] <TASK> [ 1069.271144] BUG: unable to handle page fault for address: ffffbd6ec27e4000 [ 1069.271146] #PF: supervisor read access in kernel mode [ 1069.271148] #PF: error_code(0x0000) - not-present page [ 1069.271150] PGD 100000067 P4D 100000067 PUD 1001c5067 PMD 11545d067 PTE 0 [ 1069.271156] Oops: 0000 [#2] PREEMPT SMP PTI [ 1069.271159] CPU: 1 PID: 4994 Comm: rsync Tainted: P OE 5.15.7-1-MANJARO #1 89d91431fe07b9fd339e5f86d7a009210c48fcc6 [ 1069.271163] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.15.0-0-g2dd4b9b3f840-prebuilt.qemu.org 04/01/2014 [ 1069.271165] RIP: 0010:show_trace_log_lvl+0x1a4/0x32d [ 1069.271173] Code: c7 74 fb 05 af e8 0f be 00 00 4d 85 ed 74 41 0f b6 95 37 ff ff ff 4c 89 f1 4c 89 ee 48 8d bd 50 ff ff ff e8 dc fd ff ff eb 26 <4c> 8b 3b 48 8d bd 70 ff ff ff e8 2e de 50 ff 4c 89 ff 48 89 85 28 [ 1069.271176] RSP: 0018:ffffbd6ec27e38f8 EFLAGS: 00010012 [ 1069.271179] RAX: 0000000000000000 RBX: ffffbd6ec27e3fff RCX: 0000000000000000 [ 1069.271181] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 1069.271183] RBP: ffffbd6ec27e39d8 R08: 0000000000000000 R09: 0000000000000000 [ 1069.271185] R10: 0000000000000000 R11: 0000000000000000 R12: ffff93f28dfddb80 [ 1069.271187] R13: 0000000000000000 R14: ffffffffaf086eff R15: 0000000000002b00 [ 1069.271190] FS: 00007f0b6f840580(0000) GS:ffff93f3ffc40000(0000) knlGS:0000000000000000 [ 1069.271192] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1069.271195] CR2: ffffbd6ec27e4000 CR3: 000000000dfb0000 CR4: 00000000001106e0 [ 1069.271199] Call Trace: [ 1069.271202] <TASK> [ 1069.271207] __die_body.cold+0x1a/0x1f [ 1069.271211] page_fault_oops+0x19e/0x310 [ 1069.271219] exc_page_fault+0xda/0x180 [ 1069.271227] asm_exc_page_fault+0x1e/0x30 [ 1069.271231] RIP: 0010:0xffffffade6d985ff [ 1069.271235] Code: Unable to access opcode bytes at RIP 0xffffffade6d985d5. [ 1069.271236] RSP: 0018:ffffbd6ec27e3b6f EFLAGS: 00010246 [ 1069.271239] RAX: 0000000000000000 RBX: 0000000000001800 RCX: 0000000000000000 [ 1069.271241] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 1069.271243] RBP: ffbd6ec27e3c5800 R08: 0000000000000000 R09: 0000000000000000 [ 1069.271245] R10: 0000000000000000 R11: 0000000000000000 R12: ff93f3834e26a000 [ 1069.271247] R13: 00000001112ccaff R14: ffdddbc51946c000 R15: 00000000000277ff [ 1069.271251] ? page_cache_ra_unbounded+0x1c5/0x250 [ 1069.271257] ? filemap_get_pages+0x269/0x730 [ 1069.271264] ? filemap_read+0xb9/0x360 [ 1069.271269] ? new_sync_read+0x159/0x1f0 [ 1069.271275] ? vfs_read+0xff/0x1a0 [ 1069.271279] ? ksys_read+0x67/0xf0 [ 1069.271283] ? do_syscall_64+0x5c/0x90 [ 1069.271286] ? syscall_exit_to_user_mode+0x23/0x50 [ 1069.271290] ? do_syscall_64+0x69/0x90 [ 1069.271293] ? syscall_exit_to_user_mode+0x23/0x50 [ 1069.271296] ? do_syscall_64+0x69/0x90 [ 1069.271299] ? do_syscall_64+0x69/0x90 [ 1069.271302] ? irq_exit_rcu+0x4e/0xc0 [ 1069.271306] ? entry_SYSCALL_64_after_hwframe+0x44/0xae [ 1069.271313] </TASK> [ 1069.271315] Modules linked in: ntfs3 qrtr ns joydev sg rfkill st zfs(POE) mousedev ppdev ccp iTCO_wdt i2c_i801 intel_pmc_bxt zunicode(POE) rng_core iTCO_vendor_support zzstd(OE) i2c_smbus mac_hid lpc_ich kvm parport_pc qemu_fw_cfg psmouse pcspkr parport irqbypass zlua(OE) zavl(POE) icp(POE) zcommon(POE) znvpair(POE) spl(OE) ipmi_devintf ipmi_msghandler crypto_user fuse ip_tables x_tables overlay squashfs isofs ext4 crc32c_generic crc16 mbcache jbd2 virtio_net serio_raw net_failover virtio_gpu atkbd virtio_dma_buf failover libps2 sr_mod cdrom intel_agp virtio_pci i8042 intel_gtt virtio_pci_modern_dev serio dm_snapshot dm_bufio dm_mod loop [ 1069.271380] CR2: ffffbd6ec27e4000 [ 1069.271383] ---[ end trace 7c5b9476c3cfaa50 ]--- [ 1069.271384] RIP: 0010:0xffffffade6d985ff [ 1069.271387] Code: Unable to access opcode bytes at RIP 0xffffffade6d985d5. [ 1069.271388] RSP: 0018:ffffbd6ec27e3b6f EFLAGS: 00010246 [ 1069.271390] RAX: 0000000000000000 RBX: 0000000000001800 RCX: 0000000000000000 [ 1069.271391] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000 [ 1069.271393] RBP: ffbd6ec27e3c5800 R08: 0000000000000000 R09: 0000000000000000 [ 1069.271394] R10: 0000000000000000 R11: 0000000000000000 R12: ff93f3834e26a000 [ 1069.271395] R13: 00000001112ccaff R14: ffdddbc51946c000 R15: 00000000000277ff [ 1069.271397] FS: 00007f0b6f840580(0000) GS:ffff93f3ffc40000(0000) knlGS:0000000000000000 [ 1069.271398] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1069.271400] CR2: ffffffade6d985d5 CR3: 000000000dfb0000 CR4: 00000000001106e0 QEMU invocations: C:\vol\scoop_01\SCOOPG\apps\qemu\current\qemu-system-x86_64.exe: warning: GdkPixbuf: Cannot open pixbuf loader module file 'C:\vol\scoop_01\SCOOPG\apps\qemu\current\lib\gdk-pixbuf-2.0\2.10.0\loaders.cache': No such file or directory This likely means that your installation is broken. Try running the command gdk-pixbuf-query-loaders > C:\vol\scoop_01\SCOOPG\apps\qemu\current\lib\gdk-pixbuf-2.0\2.10.0\loaders.cache to make things work again for the time being. WARNING: Image format was not specified for 'H:\gkpics01.raw' and probing guessed raw. Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted. Specify the 'raw' format explicitly to remove the restrictions. Windows Hypervisor Platform accelerator is operational C:\WINDOWS\system32>C:\vol\scoop_01\scoopg\shims\qemu-system-x86_64 -cpu qemu64 -m 4096 -machine "type=q35,kernel-irqchip=off" -accel whpx -smp "sockets=1,cores=8,threads=1" -boot d -cdrom E:\transcend\archlinux-2022.01.01-x86_64.iso -hda H:\gkpics01.raw -hdb E:\test\sgdata.vhdx -display gtk -vga virtio -rtc base=utc -netdev user,id=vmnic1,net=192.168.20.0/24,dns=192.168.20.3,dhcpstart=192.168.20.15 -device virtio-net,netdev=vmnic1 C:\vol\scoop_01\SCOOPG\apps\qemu\current\qemu-system-x86_64.exe: warning: GdkPixbuf: Cannot open pixbuf loader module file 'C:\vol\scoop_01\SCOOPG\apps\qemu\current\lib\gdk-pixbuf-2.0\2.10.0\loaders.cache': No such file or directory This likely means that your installation is broken. Try running the command gdk-pixbuf-query-loaders > C:\vol\scoop_01\SCOOPG\apps\qemu\current\lib\gdk-pixbuf-2.0\2.10.0\loaders.cache to make things work again for the time being. WARNING: Image format was not specified for 'H:\gkpics01.raw' and probing guessed raw. Automatically detecting the format is dangerous for raw images, write operations on block 0 will be restricted. Specify the 'raw' format explicitly to remove the restrictions. Windows Hypervisor Platform accelerator is operational
Fedora-Live-Workstation-iso-s are from https://koji.fedoraproject.org/koji/packageinfo?packageID=22087 https://archive.fedoraproject.org/pub/fedora/linux/development/rawhide/Workstation/x86_64/iso/ On Linux Fedora-Workstation-Live-x86_64-Rawhide-20220113.n.0.iso (5.17.0-rc1), I am not able to get a traceback, but the guest inside qemu does hang/freeze a few minutes into the rsync, whether it be terminal in GUI desktop or on linux-console. On Linux Fedora-Workstation-Live-x86_64-Rawhide-20220106.n.0.iso, (5.16.0-rc8), gives a traceback soon when sgdata is on ntfs3, pasted below. Rsync completes if sgdata is on ntfs-3g. The reason maybe that ntfs-3g is slower and so does not hit issue. The following components are suspect [A] the host kernel 5.10.90-200 [B] qemu-6.2.0-1 [C] the guest kernel 5.16.0-rc8, {paging, io, memory management} [D] the read-side ntfs3 filesystem driver If this issue is not reproducible outside of qemu, then it might be due to some interaction between guest kernel and qemu. [root@sirius gana]# qemu-system-x86_64 -cpu qemu64 -m 4096 -machine "type=q35" -accel "kvm" -smp "sockets=1,cores=8,threads=1" -boot "d" -cdrom "/vol/15KJ_Images/transcend/Fedora-Workstation-Live-x86_64-Rawhide-20220106.n.0.iso" -hda "/mnt/a16/gkpics01.raw" -hdb "/vol/15KJ_Images/test/sgdata.vhdx" -device "virtio-vga"-display "gtk,gl=on" -rtc "base=utc" -net "user" -device "virtio-net,netdev=vmnic" -netdev "user,id=vmnic,net=192.168.20.0/24,dns=192.168.20.3,dhcpstart=192.168.20.15" [ 153.791603] ------------[ cut here ]------------ [ 153.791609] kernel BUG at mm/readahead.c:151! [ 153.791632] invalid opcode: 0000 [#1] PREEMPT SMP PTI [ 153.791637] CPU: 4 PID: 2418 Comm: rsync Not tainted 5.16.0-0.rc8.55.fc36.x86_64 #1 [ 153.791640] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.15.0-1.fc35 04/01/2014 [ 153.791642] RIP: 0010:read_pages+0x191/0x280 [ 153.791649] Code: 20 00 00 00 00 48 01 43 18 eb a8 48 c7 c6 48 f8 61 90 4c 89 ef e8 9f a8 02 00 0f 0b 48 c7 c6 a8 09 5e 90 e8 91 a8 02 00 0f 0b <0f> 0b 8b 73 24 39 ce 0f 87 89 00 00 00 29 f1 48 03 73 18 89 4b 20 [ 153.791652] RSP: 0018:ffffb184c281bbc8 EFLAGS: 00010202 [ 153.791656] RAX: ffb184c281bc5800 RBX: ffffb184c281bd00 RCX: 0000000000000000 [ 153.791658] RDX: ffff96c14af52740 RSI: 0000000000000046 RDI: ffff96c14af52740 [ 153.791660] RBP: 0000000000000000 R08: ffff96c1439e8448 R09: ffff96c1439e8460 [ 153.791663] R10: 0000000000000001 R11: 0000000000000000 R12: ffffb184c281bc57 [ 153.791665] R13: 0000000000000000 R14: fffff8b4c10e7480 R15: 0000000000000126 [ 153.791667] FS: 00007f82d76afc00(0000) GS:ffff96c1bbd00000(0000) knlGS:0000000000000000 [ 153.791670] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 153.791672] CR2: 00007f12aa8f6500 CR3: 0000000110b96000 CR4: 00000000000006e0 [ 153.791677] Call Trace: [ 153.791689] <TASK> [ 153.791693] page_cache_ra_unbounded+0x1d4/0x260 [ 153.791699] filemap_get_pages+0x242/0x780 [ 153.791705] ? copy_page_to_iter+0x108/0x400 [ 153.791715] filemap_read+0xab/0x330 [ 153.791722] new_sync_read+0x108/0x180 [ 153.791729] ? 0xffffffff8f000000 [ 153.791758] vfs_read+0xf1/0x190 [ 153.791764] ksys_read+0x4f/0xc0 [ 153.791768] do_syscall_64+0x3b/0x90 [ 153.791781] entry_SYSCALL_64_after_hwframe+0x44/0xae [ 153.791792] RIP: 0033:0x7f82d77d4642 [ 153.791798] Code: c0 e9 b2 fe ff ff 50 48 8d 3d 3a d0 0b 00 e8 65 fe 01 00 0f 1f 44 00 00 f3 0f 1e fa 64 8b 04 25 18 00 00 00 85 c0 75 10 0f 05 <48> 3d 00 f0 ff ff 77 56 c3 0f 1f 44 00 00 48 83 ec 28 48 89 54 24 [ 153.791801] RSP: 002b:00007ffe9fe18788 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 153.791804] RAX: ffffffffffffffda RBX: 000055652db778c0 RCX: 00007f82d77d4642 [ 153.791806] RDX: 0000000000040000 RSI: 000055652dceb970 RDI: 0000000000000003 [ 153.791808] RBP: 0000000000040000 R08: 00000000000c0000 R09: 0000000000000010 [ 153.791810] R10: 000000000000000f R11: 0000000000000246 R12: 0000000000000000 [ 153.791812] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000040000 [ 153.791817] </TASK> [ 153.791823] Modules linked in: ntfs3 uinput snd_seq_dummy snd_hrtimer snd_seq snd_seq_device snd_timer snd soundcore nft_objref nf_conntrack_netbios_ns nf_conntrack_broadcast nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip_set rfkill nf_tables nfnetlink qrtr iTCO_wdt virtio_gpu intel_pmc_bxt iTCO_vendor_support i2c_i801 lpc_ich ppdev virtio_dma_buf i2c_smbus parport_pc parport pcspkr joydev zram isofs squashfs virtio_net serio_raw net_failover failover qemu_fw_cfg sunrpc be2iscsi bnx2i cnic uio cxgb4i cxgb4 tls cxgb3i cxgb3 mdio libcxgbi libcxgb qla4xxx iscsi_boot_sysfs iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi loop ipmi_devintf ipmi_msghandler fuse [ 153.791920] ---[ end trace 41a76e67f1229270 ]--- [ 153.791922] RIP: 0010:read_pages+0x191/0x280 [ 153.791924] Code: 20 00 00 00 00 48 01 43 18 eb a8 48 c7 c6 48 f8 61 90 4c 89 ef e8 9f a8 02 00 0f 0b 48 c7 c6 a8 09 5e 90 e8 91 a8 02 00 0f 0b <0f> 0b 8b 73 24 39 ce 0f 87 89 00 00 00 29 f1 48 03 73 18 89 4b 20 [ 153.791926] RSP: 0018:ffffb184c281bbc8 EFLAGS: 00010202 [ 153.791928] RAX: ffb184c281bc5800 RBX: ffffb184c281bd00 RCX: 0000000000000000 [ 153.791929] RDX: ffff96c14af52740 RSI: 0000000000000046 RDI: ffff96c14af52740 [ 153.791930] RBP: 0000000000000000 R08: ffff96c1439e8448 R09: ffff96c1439e8460 [ 153.791932] R10: 0000000000000001 R11: 0000000000000000 R12: ffffb184c281bc57 [ 153.791933] R13: 0000000000000000 R14: fffff8b4c10e7480 R15: 0000000000000126 [ 153.791934] FS: 00007f82d76afc00(0000) GS:ffff96c1bbd00000(0000) knlGS:0000000000000000 [ 153.791936] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 153.791937] CR2: 00007f12aa8f6500 CR3: 0000000110b96000 CR4: 00000000000006e0
on the livecd, the boot kernel, vmlinuz, is not a debug kernel, and symbols don't exist even if I use extra_vmlinux to uncompress and recover vmlinux from it, so I used the vmlinux from the kernel-debuginfo package I installed bison flex openssl-devel elfutils-liibelf-devel m4 openssl-devel zstd kernel-devel I then installed kernel-debuginfo-5.16.0-0.rc8.55.fc36.x86_64.rpm and kernel-debuginfo-common-x86_64-5.16.0-0.rc8.55.fc36.x86_64.rpm # /usr/src/kernels/5.16.0-0.rc8.55.fc36.x86_64/scripts/faddr2line /usr/lib/debug/usr/lib/modules/5.16.0-0.rc8.55.fc36.x86_64/vmlinux page_cache_ra_unbounded+0x1d4/0x260 page_cache_ra_unbounded+0x1d4/0x260: filemap_invalidate_unlock_shared at include/linux/fs.h:850 (inlined by) page_cache_ra_unbounded at mm/readahead.c:239 same as what was reported by August Wikerfors
I retested with kernel-5.17.0-rc2, the bug does not show up. [gana@sirius a16]$ uname -a Linux sirius 5.17.0-0.rc2.83.fc35.x86_64 #1 SMP PREEMPT Mon Jan 31 08:30:08 IST 2022 x86_64 x86_64 x86_64 GNU/Linux Host: Fedora-35 with kernel-5.17.0-0.rc2.83.fc35.x86_64 self-built from srpm Guest: Fedora-Workstation-Live-x86_64-Rawhide-20220201.n.0.iso with 5.17.0-0.rc2.83.fc36.x86_64 ( https://koji.fedoraproject.org/koji/buildinfo?buildID=1910892 ) qemu: 6.2.0 (qemu-6.2.0-2.fc35.1) self-built from srpm hda: raw_img/fixed_qcow2, ext4/ntfs3 (tested all 4 combinations) hdb: vhdx, ntfs3 (pre-prepared sgdata https://gitlab.com/qemu-project/qemu/-/issues/727#note_739930694 ) [root@sirius ~]# qemu-system-x86_64 -cpu qemu64 -m 4096 -machine "type=q35" -accel "kvm" -smp "sockets=1,cores=8,threads=1" -boot "d" -cdrom "/vol/15KJ_Images/transcend/Fedora-Workstation-Live-x86_64-Rawhide-20220201.n.0.iso" -hda "/mnt/a16/gkpics01.raw" -hdb "/vol/15KJ_Images/test/sgdata.vhdx" -device "virtio-vga" -display "gtk,gl=on" -rtc "base=utc" -net "user" -device "virtio-net,netdev=vmnic" -netdev "user,id=vmnic,net=192.168.20.0/24,dns=192.168.20.3,dhcpstart=192.168.20.15" * partition /dev/sda1 if necessary * mkfs.ext4 /dev/sda1 -L fs_gkpics001 * mkdir /mnt/a /mnt/b * mount t ext4 /dev/sda1 /mnt/a * mount t ntfs3 /dev/sdb2 /mnt/b * (sdate=`date` ; echo "$sdate" ; cd /mnt/b ; rsync -avH ./photos001 /mnt/a | tee /tmp/rst.txt ; echo "$sdate" ; date ) * umount /mnt/a ; * mount t ext4 /dev/sda1 /mnt/a * (sdate=`date` ; echo "$sdate" ; cd /mnt/a/photos001 ; sha256sum -c ./find.CHECKSUM --quiet ; echo "$sdate" ; date ) * dmesg -w (in another pty) * umount /mnt/a ; umount /mnt/b; I repeated the rsync test a few times. 2 vm-boots, 3 times per vm-boot Data integrity valid on full vm-restart. I will retest again with future kernel. I hope others who encountered this bug also re-test. This bug may be spurious and may be speed-timing dependent. Either a) bug is still lurking and the patches made the bug more extremely unlikely to show up or b) the patches fixed the bug. https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/diff/?id=v5.17-rc2&id2=v5.16-rc8 I retested with guest-vm running kernel-5.16.0-0.rc8 , Guest: Fedora-Workstation-Live-x86_64-Rawhide-20220106.n.0.iso Host: same as before host-kernel-ver, Fedora-35 with kernel-5.17.0-0.rc2.83.fc35.x86_64 self-built from srpm qemu: 6.2.0 (qemu-6.2.0-2.fc35.1) self-built from srpm hda: raw_img, ext4 hdb: vhdx, ntfs3 (pre-prepared sgdata https://gitlab.com/qemu-project/qemu/-/issues/727#note_739930694 ) The Bug/traceback still exists in 5.16.0-0.rc8. The traceback is thrown very soon right after starting rsync. This perhaps indicates that it is the guest-side kernel screwing up, and qemu and host-kernel not at fault. Q) If it is fixed, Any speculation as to what may have fixed it? I saw some commits to folio/page_cache_ra_unbounded. Much code under /block rewritten to use folios instead of simple-page-file 5.15.x is an LTS kernel, minus-folios, so some relevant fix to non-folio code should make it there.
I can confirm that the bug seems fixed or much more rare as of 5.17-rc2. If it's useful to anyone, the latest commit where I have been able to reproduce it is 362f533a2a1098fe95020cb59340023e9b11d062 but it may have been fixed later than that.
5.17-rc3 was also pretty good. But, in 5.17.0-0.rc4.20220216gitc5d9ae265b10.98.fc37.x86_64 something similar is happening. Details have been noted in bug 215563 comment 2, bug 215563 comment 3 . Perhaps they should have been noted here. That bug, was originally supposed to document, a non-ntfs3 related paging bug, and this one for some involvement of the ntfs3 driver. In bug 215563 comment 4, I noted that traceback in those two comments may have been triggered by ntfs3 on the read-side src-filesystem, as they did not happen when src-filesystem was mounted using ntfs-fuseblk.
I did 3 more tests with rawimg 5.17.0-0.rc4.96.fc36.x86_64 may also be pretty good. 5.17.0-0.rc4.20220217gitf71077a4d84b.99.fc37.x86_64 may have the bug. - traceback does not happen with host-kernel: 5.17.0-0.rc4.96.fc36.x86_64 qemu: qemu-img-6.2.0-2 guest-kernel: 5.17.0-0.rc4.96.fc36.x86_64 ( Fedora-Workstation-Live-x86_64-36-20220219.n.0.iso ) dstdisk: rawimg/ext4 srcdisk: vhdx/ntfs3 - traceback/hang/freeze (same as noted in bug 215563 comment 3) does happen with host-kernel: 5.17.0-0.rc4.96.fc36.x86_64 qemu: qemu-img-6.2.0-2 guest-kernel: 5.17.0-0.rc4.20220217gitf71077a4d84b.99.fc37.x86_64 ( Fedora-Workstation-Live-x86_64-Rawhide-20220218.n.0.iso ) dstdisk: rawimg/ext4 srcdisk: vhdx/ntfs3 [ 745.196372] RIP: 0010:__schedule+0x498/0x1560 : [ 745.196430] ? lock_is_held_type+0xea/0x140 [ 745.196488] ? kvm_sched_clock_read+0x14/0x40 [ 745.196497] schedule+0x4e/0xc0 [ 745.196502] io_schedule+0x47/0x70 [ 745.196506] folio_wait_bit_common+0x13e/0x430 [ 745.196515] ? dio_warn_stale_pagecache.part.0+0x50/0x50 [ 745.196521] filemap_get_pages+0x631/0x6e0 [ - traceback does not happen with host-kernel: 5.17.0-0.rc4.96.fc36.x86_64 qemu: qemu-img-6.2.0-2 guest-kernel: 5.17.0-0.rc4.20220217gitf71077a4d84b.99.fc37.x86_64 ( Fedora-Workstation-Live-x86_64-Rawhide-20220218.n.0.iso ) dstdisk: rawimg/ext4 srcdisk: vhdx/ntfs-fuseblk Perhap,s I should not try/test koji kernel builds with git-tags in them. ?
does not happen with host-kernel: 5.17.0-0.rc5.102.fc35.x86_64 qemu: qemu-img-6.2.0-2 guest-kernel: 5.17.0-0.rc5.102.fc36.x86_64 dstdisk: rawimg/ext4 srcdisk: vhdx/ntfs3