RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Bug 1918211 - Input/output error when cancelling the migration of --copy-storage-all --p2p
Summary: Input/output error when cancelling the migration of --copy-storage-all --p2p
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Red Hat Enterprise Linux 9
Classification: Red Hat
Component: libvirt
Version: 9.0
Hardware: Unspecified
OS: Unspecified
low
low
Target Milestone: rc
: ---
Assignee: Michal Privoznik
QA Contact: Han Han
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2021-01-20 09:53 UTC by Han Han
Modified: 2022-07-20 07:27 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-07-20 07:27:55 UTC
Type: Bug
Target Upstream Version: 7.6.0
Embargoed:

Attachments (Terms of Use)
VM xml, libvirtd log, qmp log (13.79 KB, application/gzip)
2021-01-20 09:53 UTC, Han Han 		no flags Details
The VM xml and libvirtd.log (493.52 KB, application/gzip)
2021-07-26 10:59 UTC, Han Han 		no flags Details
The libvirtd log during "error: End of file while reading data: : Input/output error" (142.14 KB, text/plain)
2021-08-23 10:41 UTC, Han Han 		no flags Details
View All

Description Han Han 2021-01-20 09:53:36 UTC 
Created attachment 1749009 [details]
VM xml, libvirtd log, qmp log

Description of problem:
As subject

Version-Release number of selected component (if applicable):
libvirt-7.0.0-2.module+el8.4.0+9520+ef609c5f.x86_64
qemu-kvm-5.2.0-3.module+el8.4.0+9499+42e58f08.x86_64

How reproducible:
90%

Steps to Reproduce:
1.Prepare a running VM and the migration env
2. The cancel migration loop as following:
DOM=seabios
for i in {1..200};do
        virsh migrate $DOM qemu+ssh://root@XXXX/system --live --copy-storage-all --p2p &
        sleep_time=$((10 + $RANDOM % 52))
        echo "It will sleep for $sleep_time"
        sleep $sleep_time
        virsh domjobabort $DOM
        wait
done

The the error will happen at the wait result of virsh migrate:
error: operation aborted: migration out: canceled by client

You can also reproduce it by run `virsh migrate $DOM qemu+ssh://root@XXXX/system --live --copy-storage-all --p2p` and the interrupt it by CTRL+C

Actual results:
As subject

Expected results:
No error

Additional info:
Comment 1 Han Han 2021-01-20 09:58:29 UTC 
The error happens at:
2021-01-20 01:19:50.754+0000: 106219: error : virNetSocketReadWire:1814 : End of file while reading data: : Input/output error
Comment 2 Peter Krempa 2021-01-20 10:01:05 UTC 
A slightly more useful context is:

2021-01-20 01:19:50.748+0000: 106219: info : qemuMonitorSend:950 : QEMU_MONITOR_SEND_MSG: mon=0x7f30b80441d0 msg={"execute":"migrate-set-parameters","arguments":{"compress-level":1,"compress-threads":8,"decompress-threads":2,"cpu-throttle-initial":20,"cpu-throttle-increment":10,"tls-creds":"","tls-hostname":"","max-bandwidth":134217728,"downtime-limit":300,"block-incremental":false,"xbzrle-cache-size":67108864,"max-postcopy-bandwidth":0,"multifd-channels":2},"id":"libvirt-452"}
 fd=-1
2021-01-20 01:19:50.748+0000: 107252: info : qemuMonitorIOWrite:437 : QEMU_MONITOR_IO_WRITE: mon=0x7f30b80441d0 buf={"execute":"migrate-set-parameters","arguments":{"compress-level":1,"compress-threads":8,"decompress-threads":2,"cpu-throttle-initial":20,"cpu-throttle-increment":10,"tls-creds":"","tls-hostname":"","max-bandwidth":134217728,"downtime-limit":300,"block-incremental":false,"xbzrle-cache-size":67108864,"max-postcopy-bandwidth":0,"multifd-channels":2},"id":"libvirt-452"}
 len=371 ret=371 errno=0
2021-01-20 01:19:50.751+0000: 107252: debug : qemuMonitorJSONIOProcessLine:222 : Line [{"return": {}, "id": "libvirt-452"}]
2021-01-20 01:19:50.751+0000: 107252: info : qemuMonitorJSONIOProcessLine:242 : QEMU_MONITOR_RECV_REPLY: mon=0x7f30b80441d0 reply={"return": {}, "id": "libvirt-452"}
2021-01-20 01:19:50.751+0000: 106219: debug : qemuDomainObjExitMonitorInternal:5726 : Exited monitor (mon=0x7f30b80441d0 vm=0x7f30bc1aca70 name=seabios)
2021-01-20 01:19:50.751+0000: 106219: debug : qemuDomainObjEndJob:1143 : Stopping job: async nested (async=migration out vm=0x7f30bc1aca70 name=seabios)
2021-01-20 01:19:50.751+0000: 106219: debug : qemuDomainObjEnterRemote:5833 : Entering remote (vm=0x7f30bc1aca70 name=seabios)
2021-01-20 01:19:50.751+0000: 106219: debug : virConnectUnregisterCloseCallback:1479 : conn=0x7f30ac00e8d0
2021-01-20 01:19:50.752+0000: 106219: debug : qemuDomainObjExitRemote:5844 : Exited remote (vm=0x7f30bc1aca70 name=seabios)
2021-01-20 01:19:50.754+0000: 106219: error : virNetSocketReadWire:1814 : End of file while reading data: : Input/output error
2021-01-20 01:19:50.754+0000: 106219: debug : virObjectEventStateDispose:518 : obj=0x7f30bc1cd240
2021-01-20 01:19:50.754+0000: 106219: debug : qemuMigrationSrcRestoreDomainState:140 : driver=0x7f30bc112be0, vm=0x7f30bc1aca70, pre-mig-state=nostate, state=running, reason=booted
2021-01-20 01:19:50.754+0000: 106219: debug : qemuDomainObjEndAsyncJob:1181 : Stopping async job: migration out (vm=0x7f30bc1aca70 name=seabios)

It happens after the migration is cancelled when presumably closing the connection to the destination.
Comment 3 Fangge Jin 2021-01-20 10:49:40 UTC 
See also: Bug 1821277 - virNetSocketReadWire:1806 : End of file while reading data: Input/output error
They may be same issue, and chhu has managed to reproduce bug 1821277 with just "start&&destroy vm" for multiple times(bug 1821277 comment 19)
Comment 4 Michal Privoznik 2021-01-20 13:04:25 UTC 
(In reply to Fangge Jin from comment #3)
> See also: Bug 1821277 - virNetSocketReadWire:1806 : End of file while
> reading data: Input/output error
> They may be same issue, and chhu has managed to reproduce bug 1821277 with
> just "start&&destroy vm" for multiple times(bug 1821277 comment 19)

No, in the end it wasn't because what chhu did was 'CTRL+C' virsh. Which of course leads to the I/O error message because the connection was not closed cleanly. I've summarized that in bug 1821277#c29.
Comment 5 Fangge Jin 2021-01-21 10:48:01 UTC 
@hhan
Although you said reproduce rate is 90%, I can't reproduce it at all
Comment 6 Han Han 2021-01-22 06:37:51 UTC 
(In reply to Fangge Jin from comment #5)
> @hhan
> Although you said reproduce rate is 90%, I can't reproduce it at all

Yes. I cannot reproduce that in physical machines, either. But reproduced in nested VMs
Comment 7 Michal Privoznik 2021-07-20 05:37:36 UTC 
The error is printed as a result of this code:

src/qemu/qemu_migration.c=5064=qemuMigrationSrcPerformPeer2Peer(virQEMUDriver *driver,
--
src/qemu/qemu_migration.c-5216- cleanup:
src/qemu/qemu_migration.c-5217-    virErrorPreserveLast(&orig_err);
src/qemu/qemu_migration.c:5218:    qemuDomainObjEnterRemote(vm);
src/qemu/qemu_migration.c-5219-    virConnectUnregisterCloseCallback(dconn, qemuMigrationSrcConnectionClosed);
src/qemu/qemu_migration.c-5220-    ignore_value(qemuDomainObjExitRemote(vm, false));
src/qemu/qemu_migration.c-5221-    virErrorRestore(&orig_err);
src/qemu/qemu_migration.c-5222-    return ret;
src/qemu/qemu_migration.c-5223-}


More specifically in virConnectUnregisterCloseCallback() which tries to call REMOTE_PROC_CONNECT_UNREGISTER_CLOSE_CALLBACK on the remote side.
While I agree that polluting logs with I/O errors doesn't look good, it's also a harmless message. But I think I have an idea how to fix it.
Comment 8 Michal Privoznik 2021-07-20 16:20:38 UTC 
Patch proposed upstream:

https://listman.redhat.com/archives/libvir-list/2021-July/msg00525.html
Comment 10 Michal Privoznik 2021-07-21 08:28:16 UTC 
Merged upstream as:

bab44aa963 qemu_migration: Unregister close callback only if connection still exists

v7.5.0-134-gbab44aa963
Comment 12 Han Han 2021-07-21 09:01:43 UTC 
Michal, please check the results of comment11
Comment 13 Han Han 2021-07-26 10:59:40 UTC 
Created attachment 1805869 [details]
The VM xml and libvirtd.log

Tested on libvirt v7.5.0-246-gcd72f0cd9f qemu-6.0.0-11.fc35.x86_64 as the bug report
Sometimes it will trigger this error when cancelling migration:
error: End of file while reading data: virt-ssh-helper: could not proxy traffic: End of file while reading data: Input/output error: Input/output error
Comment 14 Michal Privoznik 2021-07-26 13:34:24 UTC 
Han, I'm sorry but I'm unable to reproduce. The message is harmless though. Nevertheless, can you please attach GDB and try to get stacktrace when the error is reproduced? It should be sufficient to set breakpoint on virReportSystemErrorFull() and once the breakpoint is hit then get backtrace. I would get it myself, but I'm unable to reproduce the problem.
Comment 15 Han Han 2021-07-30 08:48:51 UTC 
Not sure if it can be reproduced on libvirt-v7.6.0-rc2 qemu-6.0.0-12.fc35.x86_64 because of the blocker issue https://gitlab.com/libvirt/libvirt/-/issues/197
Comment 18 Han Han 2021-08-04 06:09:58 UTC 
Tested on libvirt-7.6.0-1.module+el8.5.0+12097+2c77910b.x86_64 qemu-kvm-6.0.0-26.module+el8.5.0+12044+525f0ebc.x86_64, but the reproducing steps are blocked by BZ1989415 after several loops. So I am not sure if this bug is really fixed.
Comment 19 Han Han 2021-08-23 10:41:09 UTC 
Created attachment 1816821 [details]
The libvirtd log during "error: End of file while reading data: : Input/output error"

Reproduced on libvirt-7.6.0-2.module+el8.5.0+12219+a5ea13d2.x86_64 qemu-kvm-6.0.0-28.module+el8.5.0+12271+fffa967b.x86_64 as the cases of https://bugzilla.redhat.com/show_bug.cgi?id=1989415#c9
Script output:
➜  bug bash run-io.sh
Mon Aug 23 06:23:26 EDT 2021
It will sleep for 16.17              
         
Mon Aug 23 06:23:42 EDT 2021                   
It will sleep for 16.18                   
error: operation aborted: migration out: canceled by client


Mon Aug 23 06:23:59 EDT 2021
It will sleep for 17.42
error: operation aborted: migration out: canceled by client


Mon Aug 23 06:24:16 EDT 2021
It will sleep for 16.49
error: operation aborted: migration out: canceled by client


Mon Aug 23 06:24:33 EDT 2021
It will sleep for 18.75
error: End of file while reading data: : Input/output error


Mon Aug 23 06:24:52 EDT 2021
It will sleep for 16.3
error: operation aborted: migration out: canceled by client
Comment 20 Han Han 2021-08-23 10:42:22 UTC 
FailedQA according to comment19
Comment 21 Michal Privoznik 2021-08-25 11:16:05 UTC 
I couldn't really find the source of the problem. However, it doesn't really matter whether one gets I/O error or cancelled error. Therefore I think this bug can be closed. Any objections?
Comment 23 Han Han 2021-08-26 07:46:10 UTC 
(In reply to Michal Privoznik from comment #21)
> I couldn't really find the source of the problem. However, it doesn't really
> matter whether one gets I/O error or cancelled error. Therefore I think this
> bug can be closed. Any objections?

What makes the bug strange is that the 'I/O error' is never reproduced at physical host but reproduced often in nest-virt hosts. 
I think it is better to keep it open until we find the real reason.
Comment 25 John Ferlan 2021-09-08 13:31:30 UTC 
Bulk update: Move RHEL-AV bugs to RHEL9. If necessary to resolve in RHEL8, then clone to the current RHEL8 release.
Comment 31 RHEL Program Management 2022-07-20 07:27:55 UTC 
After evaluating this issue, there are no plans to address it further or fix it in an upcoming release.  Therefore, it is being closed.  If plans change such that this issue will be fixed in an upcoming release, then the bug can be reopened.
Note You need to log in before you can comment on or make changes to this bug.