Bug 1611320

Summary: org.libvirt.api.nwfilter-binding.create is not registered
Product: Red Hat Enterprise Linux 7 Reporter: yalzhang <yalzhang>
Component: libvirtAssignee: John Ferlan <jferlan>
Status: CLOSED ERRATA QA Contact: yafu <yafu>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.6CC: chhu, fjin, lmen, mtessun, tburke, xuzhang, yafu
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: libvirt-4.5.0-8.el7 Doc Type: No Doc Update
Doc Text:
undefined
Story Points: ---
Clone Of:
: 1622540 (view as bug list) Environment:
Last Closed: 2018-10-30 09:58:28 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: 1622540    

Description yalzhang@redhat.com 2018-08-02 08:37:37 UTC
Description of problem:
org.libvirt.api.nwfilter-binding.create is not registered

Version-Release number of selected component (if applicable):
polkit-0.112-17.el7.x86_64
kernel-3.10.0-924.el7.x86_64
libvirt-4.5.0-6.el7.x86_64

How reproducible:
100%

Steps to Reproduce:
1. Set "access_drivers = [ "polkit" ]" in the libvirtd configure file, and restart libvirtd
# rm -fr /var/log/libvirt/libvirtd.log
# vim /etc/libvirt/libvirtd.conf
...
log_level=2
log_outputs='2:file:/var/log/libvirt/libvirtd.log'
access_drivers = [ "polkit" ]

# systemctl restart libvirtd

2. Prepare a guest with nwfilter, and try to start it, but it can not start
# virsh dumpxml domain1 | grep /interface -B6
    <interface type='bridge'>
      <mac address='52:54:00:c6:b1:20'/>
      <source bridge='br0'/>
      <model type='virtio'/>
      <filterref filter='clean-traffic'/>
      <address type='pci' domain='0x0000' bus='0x09' slot='0x00' function='0x0'/>
    </interface>

# virsh start domain1
error: Failed to start domain domain1
error: access denied

# grep error /var/log/libvirt/libvirtd.log | grep -v info
2018-08-02 07:41:15.388+0000: 177771: error : virDBusCall:1570 : error from service: CheckAuthorization: Action org.libvirt.api.nwfilter-binding.create is not registered
2018-08-02 07:41:15.388+0000: 177771: error : virAccessManagerSanitizeError:203 : access denied
2018-08-02 07:41:15.388+0000: 177771: error : virAccessManagerSanitizeError:203 : access denied
2018-08-02 07:41:15.416+0000: 177820: error : virNetDevSendEthtoolIoctl:3072 : ethtool ioctl error: No such device
2018-08-02 07:41:15.420+0000: 177820: error : virNetDevSendEthtoolIoctl:3072 : ...

3. delete the nwfilterref, the guest can start successfully
# virsh dumpxml domain1 | grep /interface -B5
    <interface type='bridge'>
      <mac address='52:54:00:c6:b1:20'/>
      <source bridge='br0'/>
      <model type='virtio'/>
      <address type='pci' domain='0x0000' bus='0x09' slot='0x00' function='0x0'/>
    </interface>

# virsh start domain1
Domain domain1 started

Actual results:
guest can not start with nwfilterref defined in interface section when enable access_drivers = [ "polkit" ]

Expected results:
nwfilter should work well with polkit, guest should start successfully

Additional info:
Another scenario:
1. no setting about polkit in libvirtd.conf, start domain with nwfitler
# virsh dumpxml domain1 | grep /interface -B6
    <interface type='bridge'>
      <mac address='52:54:00:c6:b1:20'/>
      <source bridge='br0'/>
      <model type='virtio'/>
      <filterref filter='clean-traffic'/>
      <address type='pci' domain='0x0000' bus='0x09' slot='0x00' function='0x0'/>
    </interface>
# virsh start domain1
Domain domain1 started

2. Edit the libvirtd.conf to add the 'access_drivers = [ "polkit" ]', then restart libvirtd, the domain with nwfilter will shutdown;
# vim /etc/libvirt/libvirtd.conf

# virsh list 
 Id    Name                           State
----------------------------------------------------
 5     domain1                        running

# systemctl restart libvirtd

# virsh list --all
 Id    Name                           State
----------------------------------------------------
 -     domain1                        shut off

3. check log
# grep error /var/log/libvirt/libvirtd.log | grep -v info
2018-08-02 07:49:53.325+0000: 179504: error : virAccessDriverPolkitGetCaller:87 : access denied: Policy kit denied action org.libvirt.api.connect.getattr from <anonymous>
2018-08-02 07:49:53.325+0000: 179504: error : virAccessManagerSanitizeError:203 : access denied
2018-08-02 07:49:53.325+0000: 179504: error : virAccessManagerSanitizeError:203 : access denied
2018-08-02 07:49:53.327+0000: 179504: error : virAccessDriverPolkitGetCaller:87 : access denied: Policy kit denied action org.libvirt.api.connect.getattr from <anonymous>
2018-08-02 07:49:53.327+0000: 179504: error : virAccessManagerSanitizeError:203 : access denied
2018-08-02 07:49:53.327+0000: 179504: error : virAccessManagerSanitizeError:203 : access denied

Comment 2 John Ferlan 2018-08-21 20:24:57 UTC
I sent a patch upstream which fixes the issue:

https://www.redhat.com/archives/libvir-list/2018-August/msg01312.html

although admittedly the wording in the commit message is "weak' at best!

Comment 3 John Ferlan 2018-08-24 12:08:36 UTC
This is now pushed:

commit 6ef65e3c96d5d1f16a16daca83b81b818d461e64 
Author: John Ferlan <jferlan>
Date:   Tue Aug 21 15:58:29 2018 -0400

    access: Fix nwfilter-binding ACL access API name generation
    
    ...
    
    Generation of the ACL API policy is a "automated process"
    based on this perl script which "worked" with the changes to
    add nwfilter binding API's because they had the "nwfilter"
    prefix; however, the generated output name was incorrect
    based on the remote protocol algorithm which expected to
    generate names such as 'nwfilter-binding.action' instead
    of 'nwfilter.binding-action'.
    
    This effectively changes src/access/org.libvirt.api.policy entries:
    
      org.libvirt.api.nwfilter.binding-create ==>
          org.libvirt.api.nwfilter-binding.create
    
      org.libvirt.api.nwfilter.binding-delete ==>
          org.libvirt.api.nwfilter-binding.delete
    
      org.libvirt.api.nwfilter.binding-getattr ==>
          org.libvirt.api.nwfilter-binding.getattr
    
      org.libvirt.api.nwfilter.binding-read ==>
          org.libvirt.api.nwfilter-binding.read
    
    Signed-off-by: John Ferlan <jferlan>
    Reviewed-by: Daniel P. Berrangé <berrange>

$ git describe 6ef65e3c96d5d1f16a16daca83b81b818d461e64
v4.6.0-302-g6ef65e3c96
$

Comment 7 yafu 2018-09-10 07:53:56 UTC
Reproduced with libvirt-4.5.0-6.el7.x86_64.

Verified with libvirt-4.5.0-9.el7.x86_64.
Test steps:
1.Set "access_drivers = [ "polkit" ]" in the libvirtd configure file, and restart libvirtd
# vim /etc/libvirt/libvirtd.conf
log_level=1
log_outputs='1:file:/var/log/libvirt/libvirtd.log'
access_drivers = [ "polkit" ]

# systemctl restart libvirtd

2.Start a guest with nwfilter:
#virsh edit rhel7.6
  <interface type='network'>
      <mac address='54:52:00:54:9e:f4'/>
      <source network='default'/>
      <model type='virtio'/>
      <filterref filter='clean-traffic'/>
      <alias name='ua-04c2decd-4e33-4889-84de-a2205c777af7'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x0a' function='0x0'/>
    </interface>

#virsh start rhel7.6
Domain rhel7.6 started

3.List the nwfilter binding:
# virsh nwfilter-binding-list
 Port Dev              Filter               
------------------------------------------------------------------
 vnet0                 clean-traffic

4.Dump the XML of nwfilter binding:
# virsh nwfilter-binding-dumpxml vnet0
<filterbinding>
  <owner>
    <name>rhel7.6</name>
    <uuid>6753bb03-fbff-4004-82f5-cb2636562246</uuid>
  </owner>
  <portdev name='vnet0'/>
  <mac address='54:52:00:54:9e:f4'/>
  <filterref filter='clean-traffic'>
    <parameter name='MAC' value='54:52:00:54:9e:f4'/>
  </filterref>
</filterbinding>


5.Destroy the guest:
#virsh destroy rhel7.6
Domain rhel7.6 destroyed

6.Check the polkit api in libvirtd.log:
# cat /var/log/libvirt/libvirtd.log | grep -i nwfilter-binding 
2018-09-10 07:44:49.473+0000: 5614: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.create' for process '23226' time 43370225 uid 0
2018-09-10 07:44:49.476+0000: 5614: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.create'
2018-09-10 07:44:49.498+0000: 5614: debug : virFileMakePathHelper:3093 : path=/var/run/libvirt/nwfilter-binding mode=0777
2018-09-10 07:44:59.884+0000: 5622: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.connect.search-nwfilter-bindings' for process '24098' time 43371304 uid 0
2018-09-10 07:44:59.885+0000: 5622: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.connect.search-nwfilter-bindings'
2018-09-10 07:44:59.886+0000: 5622: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.getattr' for process '24098' time 43371304 uid 0
2018-09-10 07:44:59.886+0000: 5622: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.getattr'
2018-09-10 07:45:11.544+0000: 5615: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.getattr' for process '24799' time 43372469 uid 0
2018-09-10 07:45:11.544+0000: 5615: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.getattr'
2018-09-10 07:45:11.551+0000: 5614: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.read' for process '24799' time 43372469 uid 0
2018-09-10 07:45:11.551+0000: 5614: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.read'
2018-09-10 07:45:24.013+0000: 5616: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.getattr' for process '25569' time 43373694 uid 0
2018-09-10 07:45:24.013+0000: 5616: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.getattr'
2018-09-10 07:45:24.018+0000: 5616: debug : virAccessDriverPolkitCheck:138 : Check action 'org.libvirt.api.nwfilter-binding.delete' for process '25569' time 43373694 uid 0
2018-09-10 07:45:24.019+0000: 5616: debug : virDBusMessageIterEncode:715 : Appended basic type 'char *' varg 'char *' sig 's' val 'org.libvirt.api.nwfilter-binding.delete'

Comment 9 errata-xmlrpc 2018-10-30 09:58:28 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/RHSA-2018:3113