Bugzilla (bugzilla.redhat.com) will be under maintenance for infrastructure upgrades and will not be available on July 31st between 12:30 AM - 05:30 AM UTC. We appreciate your understanding and patience. You can follow status.redhat.com for details.
Bug 1570979 - ovs and docker does not clean interfaces
Summary: ovs and docker does not clean interfaces
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Networking
Version: 3.9.0
Hardware: Unspecified
OS: Unspecified
unspecified
high
Target Milestone: ---
: ---
Assignee: Dan Williams
QA Contact: Meng Bo
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-04-23 21:57 UTC by emahoney
Modified: 2018-04-24 17:10 UTC (History)
1 user (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-04-24 17:10:34 UTC
Target Upstream Version:


Attachments (Terms of Use)

Description emahoney 2018-04-23 21:57:48 UTC
Description of problem: After pods are deleted, network interfaces are not cleaned.  

More info : https://github.com/openshift/origin/issues/19466 

Version-Release number of selected component (if applicable):

Version
oc v3.9.14
kubernetes v1.9.1+a0ce1bc657
features: Basic-Auth GSSAPI Kerberos SPNEGO

Server https://console.example.com
openshift v3.9.14
kubernetes v1.9.1+a0ce1bc657


How reproducible:

Steps to Reproduce:Steps To Reproduce
install 3.9 containerized on rhel
create pod with rolling failure forever.
Check ip a on nodes where it gets cheduler
Current Result
veth ovs interfaces stays forever until we exceed open file limit.

Actual results:


Expected results:
veth ovs interfaces should be rotated and lifecycle.

Additional info:

Logs on the node:

Apr 22 12:59:27 node1.example.com ovs-vsctl[7579]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --if-exists clear port vethe6e4f872 qos
Apr 22 12:59:27 node1.example.com ovs-vsctl[7581]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --if-exists destroy qos
Apr 22 12:59:27 node1.example.com ovs-vsctl[7582]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --if-exists del-port br0 vethe6e4f872
Apr 22 12:59:27 node1.example.com kernel: device vethe6e4f872 left promiscuous mode
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.498Z        INFO        ovs/ovsdb.go:266 (*OvsMonitor).portDeleted        node1.example.com: Port "vethe6e4f872(87316b95-517d-43e4-9e0e-31f94ff1d8c3)" got deleted
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.502Z        INFO        ovs/ovsdb.go:143 (*OvsMonitor).bridgeUpdated        node1.example.com: Bridge "br0(b980cf78-deff-4353-a191-d64a7f4898d4)" updated
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: time="2018-04-22T12:59:27.506314517-04:00" level=debug msg="Calling POST /v1.26/containers/d9429363c9224a0b43dc48e4f6f1091a0006afba52ceeb72193abf5f3a791b14/stop?t=10"
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: time="2018-04-22T12:59:27.506432702-04:00" level=debug msg="{Action=stop, ID=d9429363c9224a0b43dc48e4f6f1091a0006afba52ceeb72193abf5f3a791b14, LoginUID=4294967295, PID=99266}"
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.506Z        INFO        ovs/ovsdb.go:143 (*OvsMonitor).bridgeUpdated        node1.example.com: Bridge "br0(b980cf78-deff-4353-a191-d64a7f4898d4)" updated
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: time="2018-04-22T12:59:27.506562885-04:00" level=debug msg="AuthZ request using plugin rhel-push-plugin"
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: time="2018-04-22T12:59:27.507069864-04:00" level=debug msg="Sending kill signal 15 to container d9429363c9224a0b43dc48e4f6f1091a0006afba52ceeb72193abf5f3a791b14"
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.506Z        INFO        ovs/ovsdb.go:216 (*OvsMonitor).interfaceDeleted        node1.example.com: Interface "vethe6e4f872(424bf131-689f-43a8-b25d-f36afaa74fa3)" got deleted
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.506Z        INFO        ovs/ovsdb.go:216 (*OvsMonitor).interfaceDeleted        node1.example.com: Interface "vethe6e4f872(424bf131-689f-43a8-b25d-f36afaa74fa3)" got deleted
Apr 22 12:59:27 node1.example.com dockerd-current[98785]: 2018-04-22T16:59:27.506Z        INFO        ovs/ovsdb.go:266 (*OvsMonitor).portDeleted        node1.example.com: Port "vethe6e4f872(87316b95-517d-43e4-9e0e-31f94ff1d8c3)" got deleted
port gets deleted. We check in openvswitch container:

sh-4.2# ovs-vsctl list-ports br0
tun0
veth497dbb87
veth8abd2e78
veth8ed4393f
vethb7c61679
vethe04e5926
vxlan0
Execute manually (it does not exist but so --if-exists):

ovs-vsctl --if-exists del-port br0 vethe6e4f872
On the node it is still there:

[root@node1 ~]# ip a | grep vethe6e4f872 -A 4
891: vethe6e4f872@if3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1450 qdisc noqueue state UP 
    link/ether 1e:2d:25:e1:61:65 brd ff:ff:ff:ff:ff:ff link-netnsid 86
    inet6 fe80::1c2d:25ff:fee1:6165/64 scope link 
       valid_lft forever preferred_lft forever
and more pilling up with each pod restart

[root@node1 ~]# ip a | grep veth | wc -l
110
Docker nothing on this apart:

Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.782Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "vethb13ca3bf(97b59365-9a46-4af2-8cb5-d0a9c0631ed1)" updated
Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.782Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "vxlan0(a2ba0fa3-c54f-47f4-86f8-720d18340c17)" updated
Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.783Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "tun0(d02bb793-4472-4b7c-aa4d-27bc76155489)" updated
Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.786Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "vxlan0(a2ba0fa3-c54f-47f4-86f8-720d18340c17)" updated
Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.786Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "tun0(d02bb793-4472-4b7c-aa4d-27bc76155489)" updated
Apr 22 13:18:07 node1.example.com dockerd-current[98785]: 2018-04-22T17:18:07.786Z        INFO        ovs/ovsdb.go:194 (*OvsMonitor).interfaceUpdated        node1.example.com: Interface "vethb13ca3bf(97b59365-9a46-4af2-8cb5-d0a9c0631ed1)" updated
another case with scale up and down pod:

Apr 22 13:24:08 node1.example.com ovs-vsctl[40862]: ovs|00001|vsctl|INFO|Called as ovs-vsctl --if-exists del-port br0 vethc80c7d5c
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: I0422 13:24:08.845377   19920 operation_generator.go:684] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/ef78f140-4651-11e8-96a0-2cc26037f111-default-token-qltmb" (OuterVolumeSpecName: "default-token-qltmb") pod "ef78f140-4651-11e8-96a0-2cc26037f111" (UID: "ef78f140-4651-11e8-96a0-2cc26037f111"). InnerVolumeSpecName "default-token-qltmb". PluginName "kubernetes.io/secret", VolumeGidValue ""
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: I0422 13:24:08.846426   19920 operation_generator.go:684] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/ef80a573-4651-11e8-96a0-2cc26037f111-default-token-qltmb" (OuterVolumeSpecName: "default-token-qltmb") pod "ef80a573-4651-11e8-96a0-2cc26037f111" (UID: "ef80a573-4651-11e8-96a0-2cc26037f111"). InnerVolumeSpecName "default-token-qltmb". PluginName "kubernetes.io/secret", VolumeGidValue ""
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: I0422 13:24:08.846729   19920 operation_generator.go:684] UnmountVolume.TearDown succeeded for volume "kubernetes.io/secret/ef733cd9-4651-11e8-96a0-2cc26037f111-default-token-qltmb" (OuterVolumeSpecName: "default-token-qltmb") pod "ef733cd9-4651-11e8-96a0-2cc26037f111" (UID: "ef733cd9-4651-11e8-96a0-2cc26037f111"). InnerVolumeSpecName "default-token-qltmb". PluginName "kubernetes.io/secret", VolumeGidValue ""
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.894Z        INFO        ovs/ovsdb.go:216 (*OvsMonitor).interfaceDeleted        node1.example.com: Interface "vethc80c7d5c(ac77dded-8a18-4674-ab68-368fc4fd79b4)" got deleted
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.895Z        INFO        ovs/ovsdb.go:266 (*OvsMonitor).portDeleted        node1.example.com: Port "vethc80c7d5c(9f725b97-03c4-42e7-94b8-187042726a31)" got deleted
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.895Z        INFO        ovs/ovsdb.go:143 (*OvsMonitor).bridgeUpdated        node1.example.com: Bridge "br0(abb318f8-3cf2-49ac-a478-b84469600b52)" updated
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.896Z        INFO        ovs/ovsdb.go:143 (*OvsMonitor).bridgeUpdated        node1.example.com: Bridge "br0(abb318f8-3cf2-49ac-a478-b84469600b52)" updated
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.896Z        INFO        ovs/ovsdb.go:216 (*OvsMonitor).interfaceDeleted        node1.example.com: Interface "vethc80c7d5c(ac77dded-8a18-4674-ab68-368fc4fd79b4)" got deleted
Apr 22 13:24:08 node1.example.com dockerd-current[19546]: 2018-04-22T17:24:08.896Z        INFO        ovs/ovsdb.go:266 (*OvsMonitor).portDeleted        node1.example.com: Port "vethc80c7d5c(9f725b97-03c4-42e7-94b8-187042726a31)" got deleted
Docker:

[root@node1 ~]# docker -v
Docker version 1.13.1, build 87f2fab/1.13.1

Comment 1 emahoney 2018-04-24 17:10:34 UTC
Closing as found a problem. Skydive network analyzer was keeping interfaces occupied.  
https://skydive-project.github.io/skydive/getting-started/kubernetes/


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