Bug 1443712

Description of problem:

Terminating a pod connected to an openvswitch mirror, causes openvswitch daemon high cpu usage (100%).

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

How reproducible: Very

Steps to Reproduce:

1. Scale up a new app.
oc scale dc/httpd1 --replicas=8
2. Log into one of the application nodes and configure open vSwitch to create a GRE interface that is used as the destination of the mirrored traffic and selected all the interfaces as the source for the mirror. Select one interface as the source of the mirror.
#Establish the GRE interface as the mirror destination and add ports to mirror
ovs-vsctl add-port br0 gre0  -- set interface gre0 type=gre options:remote_ip=10.134.129.50  -- --id=@p get port gre0  -- --id=@m create mirror name=m0 select-all=true output-port=@p  -- set bridge br0 mirrors=@m 
3. Then scale the deployment down:
oc scale dc/httpd1 --replicas=9

Actual results:

As soon as the pod is removed, you will see ovs-vswitchd goes to 100% CPU and stays there.

Expected results:

ovs-vswitchd recovers gracefully.

Additional info:

Some of our tools require packet captures for traffic going in and out of various pods and at some points, the pods could be running on the same node.  In those cases, the traffic never leaves the node so things like mirroring physical switch ports or running taps on the servers is not an option.  To gain access to the packet captures, we use the port mirroring feature of Open vSwitch and copy all the traffic going in and out the veth interface for the pods we need to monitor.  Openshift will connect a virtual Ethernet port to the pod and the other end to the vSwitch.  You can see the interfaces on the vswitch with "ovs-vsctl list-ports br0" for example.  

If at any time someone decides to modify a deployment or reduce the number of pods the replication controller is running or even if we are watching just a single pod, when the veth interface is removed from the vswitch, the problem happens.  So really any event either planned or unplanned that causes a pod to terminate will cause out problem if that interface was one of the ones we were mirroring on the vswitch.

The CPU does not recover on its own even after a few hours.  It looks like the vswitch didn't like when the virtual Ethernet interface was removed and started going absolutely log crazy.  Here's a little snip from the /var/log/openvswitch/ovs-vswitchd.log file.  Looks like the CPU going high is probably the process trying log stuff but fortunately it's being throttled. This seems pretty straight forward.  If a virtual Ethernet interface is part of an active mirror session and it's removed, open vswitch gets mad and tries to log a gazillion messages which drives the CPU hard.  

2017-04-14T12:41:54.707Z|00576|poll_loop|INFO|Dropped 126024 log messages in last 6 seconds (most recently, 0 seconds ago) due to excessive rate
2017-04-14T12:41:54.707Z|00577|poll_loop|INFO|wakeup due to 0-ms timeout at mytest/mytest-dpif.c:1571 (73% CPU usage)
2017-04-14T12:42:00.707Z|00578|poll_loop|INFO|Dropped 124953 log messages in last 6 seconds (most recently, 0 seconds ago) due to excessive rate
2017-04-14T12:42:00.707Z|00579|poll_loop|INFO|wakeup due to [POLLIN] on fd 35 (FIFO pipe:[64074894]) at mytest/mytest-dpif.c:1574 (69% CPU usage)
2017-04-14T12:42:06.707Z|00580|poll_loop|INFO|Dropped 115040 log messages in last 6 seconds (most recently, 0 seconds ago) due to excessive rate
2017-04-14T12:42:06.707Z|00581|poll_loop|INFO|wakeup due to [POLLIN] on fd 35 (FIFO pipe:[64074894]) at lib/ovs-rcu.c:206 (71% CPU usage)
2017-04-14T12:42:12.707Z|00582|poll_loop|INFO|Dropped 116971 log messages in last 6 seconds (most recently, 0 seconds ago) due to excessive rate
2017-04-14T12:42:12.707Z|00583|poll_loop|INFO|wakeup due to 0-ms timeout at mytest/mytest-dpif.c:1571 (73% CPU usage)
2017-04-14T12:42:18.706Z|00584|poll_loop|INFO|Dropped 119570 log messages in last 6 seconds (most recently, 0 seconds ago) due to excessive rate
2017-04-14T12:42:18.707Z|00585|poll_loop|INFO|wakeup due to 0-ms timeout at mytest/mytest-dpif.c:1571 (73% CPU usage)