Description of problem: error in log when veth is going quickly up and down or rename Steps to Reproduce: 1. ip l add link enp0s31f6 name asdf type macvlan; ip l set asdf name fdsa 2. watch the log Actual results: 2018-03-19 08:33:58.198+0000: 6779: error : virFileReadAll:1420 : Failed to open file '/sys/class/net/asdf/operstate': No such file or directory 2018-03-19 08:33:58.198+0000: 6779: error : virNetDevGetLinkInfo:2552 : unable to read: /sys/class/net/asdf/operstate: No such file or directory Expected results: no error
Errors when updating devices upon an event should not emit errors to logs, but rather just a warning. That goes not only for the probing of the state of the device but any other probing in the callback handler. Having said that we need to make sure libvirt knows about the new name of the device as well.
You need to be careful that when everything is finished and settled down, the nodedev driver has an up-to-date view of the new device in its cache. If we just issue a warning and continue on the same path as if the error hadn't occurred, that won't happen. Instead we need to retry after some amount of delay (implementing the delay in whatever way you think is "least bad" :-/). This problem is similar to the one where sysfs isn't yet properly populated when we get the udev event from the kernel - we'll probably have to put in a similar hack.
(In reply to Laine Stump from comment #3) That's what I meant with "we need to make sure libvirt knows about the new name of the device". Probably fits into similar category, yes.
Can anyone reproduce this on newer version of libvirt? I stopped getting these errors and I'm not sure if something changed in the setup.
Hi Martin, I've asked the customer in my ticket to test with newer version. Not sure if this is feasible though, I'll update this BZ as soon as I have any feedback from him. Regards, Davide
Hi I can reproduce this issue in the latest RHEL-7.8, and I will try RHEL-8 later. Version: libvirt-4.5.0-28.virtcov.el7.x86_64 qemu-kvm-rhev-2.12.0-38.el7.x86_64 kernel-3.10.0-1113.el7.x86_64 Steps: Terminal 1: # ifconfig em2 em2: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500 ether 18:66:da:e6:89:09 txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 device interrupt 67 # ip l add link em2 name asdf type macvlan; ip l set asdf name fdsa Terminal 2: # tail -f /var/log/libvirt/libvirtd.log ... 2019-11-26 05:55:43.411+0000: 13324: error : virFileReadAll:1460 : Failed to open file '/sys/class/net/asdf/operstate': No such file or directory 2019-11-26 05:55:43.411+0000: 13324: error : virNetDevGetLinkInfo:2552 : unable to read: /sys/class/net/asdf/operstate: No such file or directory
Same steps can hit this problem in RHEL-8.1 slow train also. Version: libvirt-4.5.0-35.module+el8.1.0+4227+b2722cb3.x86_64 qemu-kvm-2.12.0-88.module+el8.1.0+4233+bc44be3f.x86_64 kernel-4.18.0-147.0.3.el8_1.x86_64
I've merged patches upstream: 72d99b094b Avoid unnecessary error messages handling udev events abbd3a3184 node_device_udev: handle move events v6.2.0-189-g72d99b094b
Version: libvirt-6.0.0-14.module+el8.3.0+6124+819ee737.x86_64 qemu-kvm-4.2.0-19.module+el8.3.0+6478+69f490bb.x86_64 kernel-4.18.0-196.el8.x86_64 Steps: 1: In terminal 1, operate the network # ifconfig eno2 eno2: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500 ether d4:c9:ef:ce:7e:1b txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 device interrupt 89 # ip l add link eno2 name asdf type macvlan; ip l set asdf name fdsa 2: In terminal 2, check the log info # tail -f /var/log/libvirt/libvirtd.log > before_fix.log ^C # cat before_fix.log 2020-05-13 06:31:43.911+0000: 16815: info : virObjectUnref:350 : OBJECT_DISPOSE: obj=0x7f51300bc710 2020-05-13 06:31:43.911+0000: 16815: debug : virFileClose:110 : Closed fd 31 2020-05-13 06:31:43.911+0000: 16815: debug : virFileClose:110 : Closed fd 31 2020-05-13 06:31:43.911+0000: 16815: info : virObjectNew:251 : OBJECT_NEW: obj=0x7f5130176330 classname=virNodeDeviceObj 2020-05-13 06:31:43.911+0000: 16815: info : virObjectRef:386 : OBJECT_REF: obj=0x7f5130176330 2020-05-13 06:31:43.911+0000: 16815: info : virObjectNew:251 : OBJECT_NEW: obj=0x7f51300b9f90 classname=virNodeDeviceEventLifecycle 2020-05-13 06:31:43.911+0000: 16815: info : virObjectUnref:348 : OBJECT_UNREF: obj=0x7f5130176330 2020-05-13 06:31:43.911+0000: 16815: info : virObjectUnref:348 : OBJECT_UNREF: obj=0x7f51300b9f90 2020-05-13 06:31:43.911+0000: 16815: info : virObjectUnref:350 : OBJECT_DISPOSE: obj=0x7f51300b9f90 2020-05-13 06:31:43.915+0000: 16815: debug : virThreadJobClear:122 : Thread 16815 finished job nodeStateInitializeEnumerate with ret=0 2020-05-13 06:33:01.857+0000: 16747: debug : virNetlinkEventCallback:863 : dispatching to max 0 clients, called from event watch 7 2020-05-13 06:33:01.857+0000: 16747: debug : virNetlinkEventCallback:876 : event not handled. 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:863 : dispatching to max 0 clients, called from event watch 7 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:876 : event not handled. 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:863 : dispatching to max 0 clients, called from event watch 7 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:876 : event not handled. 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:863 : dispatching to max 0 clients, called from event watch 7 2020-05-13 06:33:01.858+0000: 16747: debug : virNetlinkEventCallback:876 : event not handled. 2020-05-13 06:33:01.865+0000: 16747: debug : virNetlinkEventCallback:863 : dispatching to max 0 clients, called from event watch 7 2020-05-13 06:33:01.865+0000: 16747: debug : virNetlinkEventCallback:876 : event not handled. 2020-05-13 06:33:01.869+0000: 16814: error : virFileReadAll:1426 : Failed to open file '/sys/class/net/asdf/operstate': No such file or directory 2020-05-13 06:33:01.869+0000: 16814: error : virNetDevGetLinkInfo:2444 : unable to read: /sys/class/net/asdf/operstate: No such file or directory 3. Upgrade libvirt # yum upgrade libvirt* -y # systemctl restart libvirtd # rpm -qa libvirt libvirt-6.3.0-1.module+el8.3.0+6478+69f490bb.x86_64 4. Repeat step-1 and step-2 In terminal 1 # ifconfig eno2 eno2: flags=4099<UP,BROADCAST,MULTICAST> mtu 1500 ether d4:c9:ef:ce:7e:1b txqueuelen 1000 (Ethernet) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 device interrupt 121 # ip l add link eno2 name asdf type macvlan; ip l set asdf name fdsa In terminal 2 # tail -f /var/log/libvirt/libvirtd.log > after_fix.log ^C # cat after_fix.log 2020-05-13 06:55:30.492+0000: 1751: info : virObjectUnref:347 : OBJECT_UNREF: obj=0x556e30b5e500 2020-05-13 06:55:30.492+0000: 1751: info : virObjectUnref:349 : OBJECT_DISPOSE: obj=0x556e30b5e500 2020-05-13 06:55:30.492+0000: 1751: info : virObjectUnref:347 : OBJECT_UNREF: obj=0x556e30b5e470 2020-05-13 06:55:30.492+0000: 1751: info : virObjectUnref:349 : OBJECT_DISPOSE: obj=0x556e30b5e470 2020-05-13 06:55:30.493+0000: 1751: info : virObjectUnref:347 : OBJECT_UNREF: obj=0x556e30b3cb80 2020-05-13 06:55:30.493+0000: 1751: info : virObjectUnref:349 : OBJECT_DISPOSE: obj=0x556e30b3cb80 2020-05-13 06:55:30.493+0000: 1751: info : virObjectUnref:347 : OBJECT_UNREF: obj=0x556e30b66f30 2020-05-13 06:55:30.493+0000: 1751: info : virObjectUnref:347 : OBJECT_UNREF: obj=0x556e30b59f00 2020-05-13 06:55:30.493+0000: 1751: info : virObjectUnref:349 : OBJECT_DISPOSE: obj=0x556e30b59f00 2020-05-13 06:55:30.493+0000: 1751: debug : virFileClose:134 : Closed fd 7 All the test results are as expected, move this bug to be verified.
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 (virt:8.3 bug fix and enhancement 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/RHBA-2020:5137
Covered in automated test: $ sudo avocado run --vt-type libvirt iface_rename JOB ID : 7170774117de85673d5d0c30da3571e98e483fff JOB LOG : /root/avocado/job-results/job-2020-12-23T01.09-7170774/job.log (1/1) type_specific.io-github-autotest-libvirt.virtual_network.iface_rename.check_log: PASS (11.36 s) RESULTS : PASS 1 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0 | CANCEL 0 JOB TIME : 13.36 s