Bug 1422318

Summary: After update libvirt-daemon, user started virtual machine, error message logged messages file.
Product: Red Hat Enterprise Linux 7 Reporter: Yoshinori Takahashi <hkim>
Component: libvirtAssignee: Peter Krempa <pkrempa>
Status: CLOSED ERRATA QA Contact: Lili Zhu <lizhu>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.3CC: dyuan, pkrempa, rbalakri, xuzhang
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Linux   
Whiteboard:
Fixed In Version: libvirt-3.2.0-1.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-08-01 17:21:45 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1420851    

Comment 3 Peter Krempa 2017-03-17 16:26:37 UTC
Fixed upstream by:

commit f0803dae93d62a4b8a2f67f4873c290a76d978b3
Author: Peter Krempa <pkrempa>
Date:   Fri Mar 17 16:38:47 2017 +0100

    (log|lock)daemon: Don't spam logs with IO error messages after client disconnects
    
    The log and lock protocol don't have an extra handshake to close the
    connection. Instead they just close the socket. Unfortunately that
    resulted into a lot of spurious garbage logged to the system log files:
    
    2017-03-17 14:00:09.730+0000: 4714: error : virNetSocketReadWire:1800 : End of file while reading data: Input/output error
    
    or in the journal as:
    
    Mar 13 16:19:33 xxxx virtlogd[32360]: End of file while reading data: Input/output error
    
    Use the new facility in the netserverclient to suppress the IO error
    report from the virNetSocket layer.

commit 21a2d1b69cc4e63468e23d2ca30c8124d3258a12
Author: Peter Krempa <pkrempa>
Date:   Fri Mar 17 16:18:08 2017 +0100

    rpc: serverclient: Add option to suppress errors on EOF
    
    The protocol may not use an explicit API to close the connection and
    just close the socket instead. Add option to suppress errors in such
    case.

commit 494c302c7f776292aafb2c3b8e2cba4fdd1397f2
Author: Peter Krempa <pkrempa>
Date:   Fri Mar 17 16:01:45 2017 +0100

    rpc: socket: Add possibility to suppress errors on read hangup
    
    In some cases a read error due to connection hangup is expected. This
    patch adds a flag that removes the logging of a virError in such case.

Comment 6 Lili Zhu 2017-06-14 05:44:37 UTC
Reproduce the bug with build libvirt-2.0.0-10.el7.x86_64 
steps to produce:
1. cat /etc/libvirt/libvirtd.conf
... 
log_outputs="3:journald"
...

2. restart deamon
systemctl restart libvirtd 

3. check virtlogd status and /var/log/messages

# systemctl -l status virtlogd
● virtlogd.service - Virtual machine log manager
   Loaded: loaded (/usr/lib/systemd/system/virtlogd.service; indirect; vendor preset: disabled)
   Active: active (running) since Wed 2017-06-14 12:33:35 CST; 11s ago
     Docs: man:virtlogd(8)
           http://libvirt.org
 Main PID: 1678 (virtlogd)
   CGroup: /system.slice/virtlogd.service
           └─1678 /usr/sbin/virtlogd

Jun 14 12:33:35  systemd[1]: Started Virtual machine log manager.
Jun 14 12:33:35  systemd[1]: Starting Virtual machine log manager...
Jun 14 12:33:35  virtlogd[1678]: libvirt version: 2.0.0, package: 10.el7 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2016-09-21-10:15:26, <>)
Jun 14 12:33:35  virtlogd[1678]: **End of file while reading data: Input/output error**

cat /var/log/messages
Jun 14 12:33:35 libvirtd journal: libvirt version: 2.0.0, package: 10.el7 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2016-09-21-10:15:26, <>)
Jun 14 12:33:35 libvirtd journal: **End of file while reading data: Input/output error**

Verify the bug with build libvirt-3.2.0-9.el7.x86_64 
1. yum update libvirt
2. restart deamon
systemctl restart libvirtd 
3. check virtlogd status
#  systemctl -l status virtlogd
● virtlogd.service - Virtual machine log manager
   Loaded: loaded (/usr/lib/systemd/system/virtlogd.service; indirect; vendor preset: disabled)
   Active: active (running) since Wed 2017-06-14 12:33:35 CST; 1h 2min ago
     Docs: man:virtlogd(8)
           http://libvirt.org
 Main PID: 1678 (virtlogd)
   CGroup: /system.slice/virtlogd.service
           └─1678 /usr/sbin/virtlogd

.redhat.com systemd[1]: Reloaded Virtual machine log manager.
Jun 14 12:56:20 virtlogd[1678]: 2017-06-14 04:56:20.956+0000: 2461: info : libvirt version: 3.2.0, package: 9.el7 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2017-06-07-16:25:03, <>)
Jun 14 12:56:20 virtlogd[1678]: 2017-06-14 04:56:20.956+0000: 2461: info : hostname: <>

3. check /var/log/messages

Jun 14 12:56:20 libvirtd journal: libvirt version: 3.2.0, package: 9.el7 (Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>, 2017-06-07-16:25:03, <>)
Jun 14 12:56:20 libvirtd kernel: virbr0: port 3(vnet1) entered disabled state
Jun 14 12:56:20 libvirtd kernel: device vnet1 left promiscuous mode
Jun 14 12:56:20 libvirtd kernel: virbr0: port 3(vnet1) entered disabled state
Jun 14 12:56:20 libvirtd journal: hostname: <>

As the result match the expectation, mark the bug as verified.

Comment 7 errata-xmlrpc 2017-08-01 17:21:45 UTC
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, 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/RHEA-2017:1846

Comment 8 errata-xmlrpc 2017-08-02 00:01:15 UTC
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, 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/RHEA-2017:1846