Bug 1484725 - LLDP Protocol - EnableLldpError: Failed to enable LLDP on <Port> in supervdsm logs
Summary: LLDP Protocol - EnableLldpError: Failed to enable LLDP on <Port> in supervdsm...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: vdsm
Classification: oVirt
Component: Core
Version: 4.20.0
Hardware: x86_64
OS: Linux
low
medium vote
Target Milestone: ovirt-4.1.6
: ---
Assignee: Dominik Holler
QA Contact: Meni Yakove
URL:
Whiteboard:
Depends On: 1479767
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-08-24 08:30 UTC by Michael Burman
Modified: 2017-09-19 10:02 UTC (History)
4 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-09-19 10:02:53 UTC
oVirt Team: Network
rule-engine: ovirt-4.1+


Attachments (Terms of Use)
supervdsm log (616.11 KB, application/x-gzip)
2017-08-24 08:30 UTC, Michael Burman
no flags Details

Description Michael Burman 2017-08-24 08:30:03 UTC
Created attachment 1317495 [details]
supervdsm log

Description of problem:
LLDP Protocol - EnableLldpError: Failed to enable LLDP on <Port> in supervdsm logs 

- supervdsm.log is spammed with lldp timeout errors :

ainThread::ERROR::2017-08-24 10:41:04,484::initializer::53::root::(_lldp_init) Failed to enable LLDP on ens2f1
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/network/initializer.py", line 51, in _lldp_init
    Lldp.enable_lldp_on_iface(device)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldp/lldpad.py", line 30, in enable_lldp_on_iface
    lldptool.enable_lldp_on_iface(iface, rx_only)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldpad/lldptool.py", line 46, in enable_lldp_on_iface
    raise EnableLldpError(rc, out, err, iface)
EnableLldpError: (1, "timeout\n'M00000001C3040000000c06ens2f1000badminStatus0002rx' command timed out.\n", '', 'ens2f1')

systemctl status lldpad
● lldpad.service - Link Layer Discovery Protocol Agent Daemon.
   Loaded: loaded (/usr/lib/systemd/system/lldpad.service; disabled; vendor preset: disabled)
   Active: active (running) since Thu 2017-08-17 17:25:15 IDT; 6 days ago
 Main PID: 1869 (lldpad)
   CGroup: /system.slice/lldpad.service
           └─1869 /usr/sbin/lldpad -t

[root@navy-vds1 ~]# lldptool set-lld -i ens2f1 adminStatus=rxtx
adminStatus = rxtx

[root@navy-vds1 ~]# lldptool get-lld -i ens2f1 adminStatus
adminStatus=rxtx

[root@navy-vds1 ~]# lldptool get-tlv -n -i ens2f1
Chassis ID TLV
        MAC: 18:ef:63:a1:75:0c
Port ID TLV
        Local: Gi0/12
Time to Live TLV
        120
System Name TLV
        rack03-sw02-lab4.tlv.redhat.com
System Description TLV
        Cisco IOS Software, C3560 Software (C3560-ADVIPSERVICESK9-M), Version 12.2(44)SE6, RELEASE SOFTWARE (fc1)
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Mon 09-Mar-09 17:42 by gereddy
Port Description TLV
        GigabitEthernet0/12
System Capabilities TLV
        System capabilities:  Bridge, Router
        Enabled capabilities: Bridge
Port VLAN ID TLV
        PVID: 161
MAC/PHY Configuration Status TLV
        Auto-negotiation supported and enabled
        PMD auto-negotiation capabilities: 0xc036
        MAU type: 1000 BaseTFD
End of LLDPDU TLV

Version-Release number of selected component (if applicable):
vdsm-4.20.2-111.gita9f6d88.el7.centos.x86_64

How reproducible:
Seems to be always in the background on all hosts, although the lldpad service is running and the port status is enabled.

Comment 1 Dan Kenigsberg 2017-08-24 09:58:07 UTC
I think we should require selinux-policy-targeted >= 3.13.1-166.el7_4.3 explicitly.

Michael, can you check if it solves this?

Comment 2 Michael Burman 2017-08-24 12:56:10 UTC
(In reply to Dan Kenigsberg from comment #1)
> I think we should require selinux-policy-targeted >= 3.13.1-166.el7_4.3
> explicitly.
> 
> Michael, can you check if it solves this?

Dan we already running selinux-policy-targeted-3.13.1-166.el7.noarch

Comment 3 Dan Kenigsberg 2017-08-27 09:17:07 UTC
The trailing _4.3 in the rpm is the important one, in this context. It tells that I'm asking you to take the rhel-7.4.1 package, not the plain 7.4.0 one.

Comment 4 Michael Burman 2017-08-27 09:30:19 UTC
(In reply to Dan Kenigsberg from comment #3)
> The trailing _4.3 in the rpm is the important one, in this context. It tells
> that I'm asking you to take the rhel-7.4.1 package, not the plain 7.4.0 one.

I can't find such package any where. Please provide me one if you want me to test this. I can only find our latest which we already running.

Comment 8 Michael Burman 2017-08-30 15:20:26 UTC
Hi Dominik,

As we saw together on my hosts, the next messages appears right after we installing selinux-policy-targeted-3.13.1-166.el7_4.3.noarch on all of the ports- 

MainThread::ERROR::2017-08-28 07:44:09,734::initializer::53::root::(_lldp_init) Failed to enable LLDP on enp4s0
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/network/initializer.py", line 51, in _lldp_init
    Lldp.enable_lldp_on_iface(device)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldp/lldpad.py", line 30, in enable_lldp_on_iface
    lldptool.enable_lldp_on_iface(iface, rx_only)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldpad/lldptool.py", line 46, in enable_lldp_on_iface
    raise EnableLldpError(rc, out, err, iface)
EnableLldpError: (255, '', 'connect: Connection refused\nFailed to connect to lldpad - clif_open: Invalid argument\n', 'enp4s0')

Do we ok with it? 
If yes, then those messages should be removed from the log and handled by vdsm.

Comment 9 Dominik Holler 2017-08-30 15:24:54 UTC
I expect that this is related to update process of SELinux rules.
Are the messages produced after reboot?

Comment 10 Michael Burman 2017-08-31 08:08:19 UTC
(In reply to Dominik Holler from comment #9)
> I expect that this is related to update process of SELinux rules.
> Are the messages produced after reboot?

Yes the messages are still produced indeed, i have updated to selinux-policy-targeted-3.13.1-166.el7_4.3.noarch few days ago(also rebooted the host) and i still see this error messages in supervdsm log(for example from last night) - 

MainThread::ERROR::2017-08-30 22:26:24,711::initializer::53::root::(_lldp_init) Failed to enable LLDP on enp6s0f0
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/vdsm/network/initializer.py", line 51, in _lldp_init
    Lldp.enable_lldp_on_iface(device)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldp/lldpad.py", line 30, in enable_lldp_on_iface
    lldptool.enable_lldp_on_iface(iface, rx_only)
  File "/usr/lib/python2.7/site-packages/vdsm/network/lldpad/lldptool.py", line 46, in enable_lldp_on_iface
    raise EnableLldpError(rc, out, err, iface)
EnableLldpError: (255, '', 'connect: Connection refused\nFailed to connect to lldpad - clif_open: Invalid argument\n', 'enp6s0f0')

rpm -qa | grep target
selinux-policy-targeted-3.13.1-166.el7_4.3.noarch

Also note, that this error messages appear both on hosts with the updated package and without.

Comment 11 Michael Burman 2017-08-31 08:10:05 UTC
Also with the newer version selinux-policy-targeted-3.13.1-166.el7_4.4.noarch

Comment 12 Dominik Holler 2017-08-31 08:14:13 UTC
> 'connect: Connection refused\nFailed to connect to lldpad - clif_open: Invalid argument\n', 'enp6s0f0'

This is a other error message, maybe we should track this in a new bug.

Comment 13 Michael Burman 2017-08-31 08:19:49 UTC
(In reply to Dominik Holler from comment #12)
> > 'connect: Connection refused\nFailed to connect to lldpad - clif_open: Invalid argument\n', 'enp6s0f0'
> 
> This is a other error message, maybe we should track this in a new bug.

This are the error messages we see after package update. We don't see the original error message(about the timeout) in comment#0 after updating the package , but we do see this new error messages. 
If you think we need a new bug i don't mind, let me know what to do.

Comment 14 Michael Burman 2017-08-31 08:32:00 UTC
(In reply to Michael Burman from comment #13)
> (In reply to Dominik Holler from comment #12)
> > > 'connect: Connection refused\nFailed to connect to lldpad - clif_open: Invalid argument\n', 'enp6s0f0'
> > 
> > This is a other error message, maybe we should track this in a new bug.
> 
> This are the error messages we see after package update. We don't see the
> original error message(about the timeout) in comment#0 after updating the
> package , but we do see this new error messages. 
> If you think we need a new bug i don't mind, let me know what to do.

New bug has been reported for the new errors after selinux-policy-targeted update , see BZ 1487078

Comment 15 Dan Kenigsberg 2017-09-04 18:42:55 UTC
Thanks for filing a fresh bug.

Please reopen this bug if you see other "timeout" error on a host that was booted with el7.4.1's selinux-policy.

Comment 16 Michael Burman 2017-09-06 05:34:40 UTC
Verified with -
vdsm-4.19.30-1.el7ev.x86_64
selinux-policy-targeted-3.13.1-166.el7_4.4.noarch
selinux-policy-3.13.1-166.el7_4.4.noarch


Note You need to log in before you can comment on or make changes to this bug.