Created attachment 1816085 [details] importer.log Description of problem: MTV migration of a CirrOS VM to NFS target storage is running endlessly. The reason: The VM import of a CirrOS VM to NFS target storage fails - the cdi importer pod crashes (importer pod log attached). MTV migration of a CirrOS VM to Ceph-rbd/Block target storage ends successfully (the VM import it runs ends successfully). Version-Release number of selected component (if applicable): CNV-4.8.1-18, iib-97626 MTV-2.1.0-53 How reproducible: always
Bumped severity because I think that it's a bigger problem. Might be because MTV assumes we round to 512 bytes in https://github.com/kubevirt/vm-import-operator/pull/479/files But as of https://github.com/kubevirt/containerized-data-importer/pull/1873 we align to 1Mi (also backported to all release branches)
Can you please verify with hco-bundle-registry-container-v4.8.2-9.
Actually, it's not part of hco-bundle-registry-container-v4.8.2-9. Moving the BZ back to MODIFIED.
Can you please verify with hco-bundle-registry-container-v4.8.2-10 ?
Created attachment 1819642 [details] Screenshot of VM Import fail
Bug was tested on CNV-4.8.2-12 and it failed (Screenshot is attached)
Is it possible to get the pod log? The screenshot shows that the pod is in CrashLoopBackoff state. So, the log may have more explicit info about why it fails.
I0901 16:10:38.236729 1 importer.go:52] Starting importer I0901 16:10:38.237170 1 importer.go:135] begin import process I0901 16:10:38.332294 1 imageio-datasource.go:304] waiting for disk to unlock I0901 16:10:54.198856 1 http-datasource.go:251] Attempting to get certs from /certs/ca.pem I0901 16:10:54.212895 1 data-processor.go:323] Calculating available size E0901 16:10:54.214515 1 data-processor.go:327] exit status 1, blockdev: ioctl error on BLKGETSIZE64: Inappropriate ioctl for device I0901 16:10:54.214527 1 data-processor.go:335] Checking out file system volume size. I0901 16:10:54.214629 1 data-processor.go:343] Request image size not empty. I0901 16:10:54.214639 1 data-processor.go:348] Target size 42Mi. I0901 16:10:54.215074 1 util.go:39] deleting file: /data/disk.img I0901 16:10:54.215685 1 data-processor.go:231] New phase: TransferDataFile I0901 16:10:54.216358 1 util.go:170] Writing data... I0901 16:10:54.330444 1 data-processor.go:231] New phase: Resize W0901 16:10:54.341011 1 data-processor.go:310] Available space less than requested size, resizing image to available space 40894464. I0901 16:10:54.341031 1 data-processor.go:316] Expanding image size to: 40894464 E0901 16:10:54.345650 1 prlimit.go:174] qemu-img failed output is: E0901 16:10:54.345664 1 prlimit.go:175] E0901 16:10:54.345673 1 prlimit.go:176] qemu-img: Use the --shrink option to perform a shrink operation. qemu-img: warning: Shrinking an image will delete all data beyond the shrunken image's end. Before performing such an operation, make sure there is no important data there. E0901 16:10:54.345698 1 data-processor.go:228] exit status 1 qemu-img execution failed kubevirt.io/containerized-data-importer/pkg/system.executeWithLimits /remote-source/app/pkg/system/prlimit.go:178 kubevirt.io/containerized-data-importer/pkg/system.ExecWithLimits /remote-source/app/pkg/system/prlimit.go:111 kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Resize /remote-source/app/pkg/image/qemu.go:160 kubevirt.io/containerized-data-importer/pkg/importer.ResizeImage /remote-source/app/pkg/importer/data-processor.go:317 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:268 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Error resizing image /data/disk.img kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Resize /remote-source/app/pkg/image/qemu.go:163 kubevirt.io/containerized-data-importer/pkg/importer.ResizeImage /remote-source/app/pkg/importer/data-processor.go:317 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:268 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Resize of image failed kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:270 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Unable to resize disk image to requested size kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:222 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 E0901 16:10:54.345812 1 importer.go:191] exit status 1 qemu-img execution failed kubevirt.io/containerized-data-importer/pkg/system.executeWithLimits /remote-source/app/pkg/system/prlimit.go:178 kubevirt.io/containerized-data-importer/pkg/system.ExecWithLimits /remote-source/app/pkg/system/prlimit.go:111 kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Resize /remote-source/app/pkg/image/qemu.go:160 kubevirt.io/containerized-data-importer/pkg/importer.ResizeImage /remote-source/app/pkg/importer/data-processor.go:317 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:268 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Error resizing image /data/disk.img kubevirt.io/containerized-data-importer/pkg/image.(*qemuOperations).Resize /remote-source/app/pkg/image/qemu.go:163 kubevirt.io/containerized-data-importer/pkg/importer.ResizeImage /remote-source/app/pkg/importer/data-processor.go:317 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:268 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Resize of image failed kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).resize /remote-source/app/pkg/importer/data-processor.go:270 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:220 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374 Unable to resize disk image to requested size kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessDataWithPause /remote-source/app/pkg/importer/data-processor.go:222 kubevirt.io/containerized-data-importer/pkg/importer.(*DataProcessor).ProcessData /remote-source/app/pkg/importer/data-processor.go:165 main.main /remote-source/app/cmd/cdi-importer/importer.go:189 runtime.main /usr/lib/golang/src/runtime/proc.go:204 runtime.goexit /usr/lib/golang/src/runtime/asm_amd64.s:1374
Does this need a backport or can it be moved to ON_QA? The 4.8.2 train is leaving the station soon and we need to get this finished or pushed out.
It needs to be backported to 4.8, since the initial calculation change was backported to 4.8 and even further back. Then, the decision to have it in 4.8.2 is not really mine. The code freeze is on Tuesday, September 7th, so we should be able to get it in, but today is Labor Day, so it might be tough.
Please verify with hco-registry-bundle-container-v4.8.2-15 / iib:106992.
Verified on CNV-4.8.2-15. The cdi Importer log given below: I0909 05:28:02.838932 1 importer.go:52] Starting importer I0909 05:28:02.840285 1 importer.go:135] begin import process I0909 05:28:03.840096 1 http-datasource.go:251] Attempting to get certs from /certs/ca.pem I0909 05:28:03.878360 1 data-processor.go:323] Calculating available size I0909 05:28:03.880009 1 data-processor.go:335] Checking out file system volume size. I0909 05:28:03.880549 1 data-processor.go:343] Request image size not empty. I0909 05:28:03.880595 1 data-processor.go:348] Target size 1136234735. I0909 05:28:03.883500 1 data-processor.go:231] New phase: TransferDataFile I0909 05:28:03.886762 1 util.go:170] Writing data... I0909 05:28:04.883925 1 prometheus.go:69] 100.00 I0909 05:28:05.884885 1 prometheus.go:69] 100.00 I0909 05:28:06.885250 1 prometheus.go:69] 100.00 I0909 05:28:07.239082 1 data-processor.go:231] New phase: Resize W0909 05:28:07.459376 1 data-processor.go:310] Available space less than requested size, resizing image to available space 1073741824. I0909 05:28:07.459416 1 data-processor.go:313] No need to resize image. Requested size: 1136234735, Image size: 1073741824. I0909 05:28:07.459429 1 data-processor.go:237] Validating image I0909 05:28:07.474175 1 data-processor.go:231] New phase: Complete I0909 05:28:07.474427 1 importer.go:217] Import Complete
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory (Moderate: OpenShift Virtualization 4.8.2 Images security and bug fix update), and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHSA-2021:3598