diff mbox

[ovs-dev] About a race condition between handle_upcalls and revalidate

Message ID 1517196b-2d59-95e0-94f6-b1a924f8df3f@mellanox.com
State Not Applicable
Headers show

Commit Message

Paul Blakey March 20, 2017, 4:19 p.m. UTC 
On 19/03/2017 16:28, Paul Blakey wrote:
> Hi all,
>
> While using out patches for HW offload we've noticed we get a ovs
> assertion at transition ukey, which tries to
> transition the ukey state from EVICTED back to OPERATIONAL.
> With furthur investigation it seem that this can happen without our HW
> offload patches as there might be a race between handle_upcalls and
> revalidate.
>
> The procedure is as such:
>
> handle_upcalls receives a new upcall and creates a new ukey, its state
> is VISIBLE, it then it installs a flow (FLOW_PUT) to the datapat and
> upon success wants to set the ukey state to OPERATIONAL (line 1408). for
> that the handler running handle_upcalls wants to reaquirce the ukey
> lock, but in the meantime revalidators dump (line 2261) the already
> inserted flow and want to delete this flow (line 2328, say because of
> openflow db changes, or aging). The revalidator deletes the flow and
> moves the ukey from
> VISIBLE -> OPERATIONAL (line 2320) -> EVICTING (line 2220) -> EVICTED
> (line 2134)
>
> finally handler succesfuly acquires the flow and now set the state to
> OPERERTIONAL which will cause the assert in transition_ukey.
>
> Line numbers in question are from ofproto/ofproto-dpif-upcall.c
>
> I can provide a test the could show this happening, basicly adding a
> sleep before (writing it now).
>
> Thanks,
> Paul Blakey.
>
>
>

New test patch below,
To reproduce run this bash script:
########## START OF SCRIPT ###############################
#setup: veth0 <-> veth1 <-> OVS <->  veth2@ns0 <-> veth3@ns0
#       VM1_IP                                      VM2_IP

VM1_IP=77.77.77.7
VM2_IP=77.77.77.8

echo "deleting bridges (if ovs is running)"
ovs-vsctl list-br | xargs -r -l ovs-vsctl del-br

echo "deleting namespace"
ip netns del ns0 &> /dev/null
ip netns add ns0

echo "setup veth0-3"
ip link del veth0 &> /dev/null
ip link del veth1 &> /dev/null
ip link del veth2 &> /dev/null
ip link del veth3 &> /dev/null
ip link add veth0 type veth peer name veth1
ip link add veth2 type veth peer name veth3

echo "setup remote vm(veth3) $VM2_IP in namespace"
ip link set veth3 netns ns0
ip netns exec ns0 ifconfig veth3 $VM2_IP/24 up

echo "setup local vm(veth0) $VM1_IP"

ifconfig veth0 $VM1_IP/24 up
ifconfig veth1 up
ifconfig veth2 up

echo "restart ovs and delete bridges (if ovs wasn't running)"
systemctl restart openvswitch
sleep 2
ovs-vsctl list-br | xargs -r -l ovs-vsctl del-br

ovs-vsctl set Open_vSwitch . other_config:max-idle=250
ovs-vsctl set Open_vSwitch . other_config:n-handler-threads=1
ovs-vsctl set Open_vSwitch . other_config:n-revalidator-threads=5

echo "setup ovs with veth"
ovs-vsctl add-br brv-1
ovs-vsctl add-port brv-1 veth1
ovs-vsctl add-port brv-1 veth2

echo "pinging remote VM $VM2_IP"
ping $VM2_IP -i 2

##################END OF BASH SCRIPT################

and follow ovs-vswitchd.log
Here is the ovs-vswitchd.log I get:

2017-03-20T16:01:20.322Z|00001|vlog|INFO|opened log file 
/var/log/openvswitch/ovs-vswitchd.log
2017-03-20T16:01:20.327Z|00002|ovs_numa|INFO|Discovered 16 CPU cores on 
NUMA node 0
2017-03-20T16:01:20.327Z|00003|ovs_numa|INFO|Discovered 16 CPU cores on 
NUMA node 1
2017-03-20T16:01:20.327Z|00004|ovs_numa|INFO|Discovered 2 NUMA nodes and 
32 CPU cores
2017-03-20T16:01:20.327Z|00005|reconnect|INFO|unix:/var/run/openvswitch/db.sock: 
connecting...
2017-03-20T16:01:20.327Z|00006|reconnect|INFO|unix:/var/run/openvswitch/db.sock: 
connected
2017-03-20T16:01:20.334Z|00007|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports recirculation
2017-03-20T16:01:20.334Z|00008|ofproto_dpif|INFO|system@ovs-system: MPLS 
label stack length probed as 1
2017-03-20T16:01:20.334Z|00009|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports truncate action
2017-03-20T16:01:20.335Z|00010|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports unique flow ids
2017-03-20T16:01:20.335Z|00011|ofproto_dpif|INFO|system@ovs-system: 
Datapath does not support clone action
2017-03-20T16:01:20.335Z|00012|ofproto_dpif|INFO|system@ovs-system: Max 
sample nesting level probed as 3
2017-03-20T16:01:20.335Z|00013|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_state
2017-03-20T16:01:20.335Z|00014|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_zone
2017-03-20T16:01:20.335Z|00015|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_mark
2017-03-20T16:01:20.335Z|00016|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_label
2017-03-20T16:01:20.335Z|00017|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_state_nat
2017-03-20T16:01:20.335Z|00018|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_orig_tuple
2017-03-20T16:01:20.366Z|00001|ofproto_dpif_upcall(handler1)|INFO|received 
packet on unassociated datapath port 0
2017-03-20T16:01:20.367Z|00019|bridge|INFO|bridge brv-1: added interface 
brv-1 on port 65534
2017-03-20T16:01:20.373Z|00020|bridge|INFO|bridge brv-1: added interface 
veth2 on port 2
2017-03-20T16:01:20.379Z|00021|bridge|INFO|bridge brv-1: added interface 
veth1 on port 1
2017-03-20T16:01:20.380Z|00022|bridge|INFO|bridge brv-1: using datapath 
ID 00005a7f2804ff4f
2017-03-20T16:01:20.380Z|00023|connmgr|INFO|brv-1: added service 
controller "punix:/var/run/openvswitch/brv-1.mgmt"
2017-03-20T16:01:20.397Z|00024|bridge|INFO|ovs-vswitchd (Open vSwitch) 
2.7.90
2017-03-20T16:01:20.903Z|00001|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: CREATED -> VISIBLE
2017-03-20T16:01:20.903Z|00002|ofproto_dpif_upcall(handler8)|INFO|put 
count: 1
2017-03-20T16:01:20.903Z|00003|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: VISIBLE -> OPERATIONAL
2017-03-20T16:01:21.031Z|00004|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: CREATED -> VISIBLE
2017-03-20T16:01:21.031Z|00005|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: CREATED -> VISIBLE
2017-03-20T16:01:21.031Z|00006|ofproto_dpif_upcall(handler8)|INFO|put 
count: 2
2017-03-20T16:01:21.031Z|00007|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: VISIBLE -> OPERATIONAL
2017-03-20T16:01:21.031Z|00008|ofproto_dpif_upcall(handler8)|INFO|put 
count: 3
2017-03-20T16:01:21.031Z|00009|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: VISIBLE -> OPERATIONAL
2017-03-20T16:01:21.155Z|00001|ofproto_dpif_upcall(revalidator9)|INFO|revalidate 
2345 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:21.155Z|00002|ofproto_dpif_upcall(revalidator9)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: OPERATIONAL -> EVICTING
2017-03-20T16:01:21.155Z|00003|ofproto_dpif_upcall(revalidator9)|INFO|revalidate 
2345 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:21.155Z|00004|ofproto_dpif_upcall(revalidator9)|INFO|revalidate 
2345 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:21.155Z|00005|ofproto_dpif_upcall(revalidator9)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: EVICTING -> EVICTED
2017-03-20T16:01:21.156Z|00001|ofproto_dpif_upcall(revalidator13)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:1591b637-55f9-4479-941e-7a44062b0a7e: EVICTED -> DELETED
2017-03-20T16:01:21.406Z|00006|ofproto_dpif_upcall(revalidator9)|INFO|revalidate 
2345 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:21.406Z|00007|ofproto_dpif_upcall(revalidator9)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: OPERATIONAL -> EVICTING
2017-03-20T16:01:21.406Z|00008|ofproto_dpif_upcall(revalidator9)|INFO|revalidate 
2345 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:21.406Z|00009|ofproto_dpif_upcall(revalidator9)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: OPERATIONAL -> EVICTING
2017-03-20T16:01:21.406Z|00010|ofproto_dpif_upcall(revalidator9)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: EVICTING -> EVICTED
2017-03-20T16:01:21.406Z|00011|ofproto_dpif_upcall(revalidator9)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: EVICTING -> EVICTED
2017-03-20T16:01:21.406Z|00001|ofproto_dpif_upcall(revalidator10)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:2c4a95de-c670-4301-ac4e-d3b32483894e: EVICTED -> DELETED
2017-03-20T16:01:21.406Z|00001|ofproto_dpif_upcall(revalidator12)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:72131844-bada-4d2a-bb84-75e5f7a031c6: EVICTED -> DELETED
2017-03-20T16:01:21.927Z|00010|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:87e128d2-8182-4488-9af2-d65b81402180: CREATED -> VISIBLE
2017-03-20T16:01:21.927Z|00011|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:f04759b5-22b6-4328-94a0-ee6654016a18: CREATED -> VISIBLE
2017-03-20T16:01:21.927Z|00012|ofproto_dpif_upcall(handler8)|INFO|put 
count: 4
2017-03-20T16:01:21.927Z|00013|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:87e128d2-8182-4488-9af2-d65b81402180: VISIBLE -> OPERATIONAL
2017-03-20T16:01:21.927Z|00014|ofproto_dpif_upcall(handler8)|INFO|put 
count: 5
2017-03-20T16:01:21.927Z|00015|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:f04759b5-22b6-4328-94a0-ee6654016a18: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.055Z|00016|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:b82a17b0-a9bf-449f-b6a2-3634a7b811b5: CREATED -> VISIBLE
2017-03-20T16:01:22.055Z|00017|ofproto_dpif_upcall(handler8)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:2701af7d-8094-4229-838e-070838c79df4: CREATED -> VISIBLE
2017-03-20T16:01:22.055Z|00018|ofproto_dpif_upcall(handler8)|INFO|put 
count: 6
2017-03-20T16:01:22.055Z|00019|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:b82a17b0-a9bf-449f-b6a2-3634a7b811b5: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.055Z|00020|ofproto_dpif_upcall(handler8)|INFO|put 
count: 7
2017-03-20T16:01:22.055Z|00021|ofproto_dpif_upcall(handler8)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:2701af7d-8094-4229-838e-070838c79df4: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.158Z|00025|ofproto_dpif_upcall|INFO|reval_op_init 
2245 state transition for ukey 
ufid:2701af7d-8094-4229-838e-070838c79df4: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.158Z|00026|ofproto_dpif_upcall|INFO|push_dp_ops 2159 
state transition for ukey ufid:2701af7d-8094-4229-838e-070838c79df4: 
EVICTING -> EVICTED
2017-03-20T16:01:22.158Z|00027|ofproto_dpif_upcall|INFO|ukey_delete 1825 
state transition for ukey ufid:2701af7d-8094-4229-838e-070838c79df4: 
EVICTED -> DELETED
2017-03-20T16:01:22.158Z|00028|ofproto_dpif_upcall|INFO|reval_op_init 
2245 state transition for ukey 
ufid:f04759b5-22b6-4328-94a0-ee6654016a18: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.158Z|00029|ofproto_dpif_upcall|INFO|push_dp_ops 2159 
state transition for ukey ufid:f04759b5-22b6-4328-94a0-ee6654016a18: 
EVICTING -> EVICTED
2017-03-20T16:01:22.158Z|00030|ofproto_dpif_upcall|INFO|ukey_delete 1825 
state transition for ukey ufid:f04759b5-22b6-4328-94a0-ee6654016a18: 
EVICTED -> DELETED
2017-03-20T16:01:22.158Z|00031|ofproto_dpif_upcall|INFO|reval_op_init 
2245 state transition for ukey 
ufid:87e128d2-8182-4488-9af2-d65b81402180: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.158Z|00032|ofproto_dpif_upcall|INFO|push_dp_ops 2159 
state transition for ukey ufid:87e128d2-8182-4488-9af2-d65b81402180: 
EVICTING -> EVICTED
2017-03-20T16:01:22.158Z|00033|ofproto_dpif_upcall|INFO|ukey_delete 1825 
state transition for ukey ufid:87e128d2-8182-4488-9af2-d65b81402180: 
EVICTED -> DELETED
2017-03-20T16:01:22.158Z|00034|ofproto_dpif_upcall|INFO|reval_op_init 
2245 state transition for ukey 
ufid:b82a17b0-a9bf-449f-b6a2-3634a7b811b5: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.158Z|00035|ofproto_dpif_upcall|INFO|push_dp_ops 2159 
state transition for ukey ufid:b82a17b0-a9bf-449f-b6a2-3634a7b811b5: 
EVICTING -> EVICTED
2017-03-20T16:01:22.158Z|00036|ofproto_dpif_upcall|INFO|ukey_delete 1825 
state transition for ukey ufid:b82a17b0-a9bf-449f-b6a2-3634a7b811b5: 
EVICTED -> DELETED
2017-03-20T16:01:22.268Z|00037|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports recirculation
2017-03-20T16:01:22.268Z|00038|ofproto_dpif|INFO|system@ovs-system: MPLS 
label stack length probed as 1
2017-03-20T16:01:22.268Z|00039|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports truncate action
2017-03-20T16:01:22.268Z|00040|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports unique flow ids
2017-03-20T16:01:22.269Z|00041|ofproto_dpif|INFO|system@ovs-system: 
Datapath does not support clone action
2017-03-20T16:01:22.269Z|00042|ofproto_dpif|INFO|system@ovs-system: Max 
sample nesting level probed as 3
2017-03-20T16:01:22.269Z|00043|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_state
2017-03-20T16:01:22.269Z|00044|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_zone
2017-03-20T16:01:22.269Z|00045|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_mark
2017-03-20T16:01:22.269Z|00046|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_label
2017-03-20T16:01:22.269Z|00047|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_state_nat
2017-03-20T16:01:22.269Z|00048|ofproto_dpif|INFO|system@ovs-system: 
Datapath supports ct_orig_tuple
2017-03-20T16:01:22.280Z|00001|ofproto_dpif_upcall(handler26)|INFO|received 
packet on unassociated datapath port 0
2017-03-20T16:01:22.290Z|00049|bridge|INFO|bridge brv-1: added interface 
brv-1 on port 65534
2017-03-20T16:01:22.290Z|00050|bridge|INFO|bridge brv-1: using datapath 
ID 00003ed7a2298140
2017-03-20T16:01:22.290Z|00051|connmgr|INFO|brv-1: added service 
controller "punix:/var/run/openvswitch/brv-1.mgmt"
2017-03-20T16:01:22.325Z|00052|bridge|INFO|bridge brv-1: added interface 
veth1 on port 1
2017-03-20T16:01:22.345Z|00053|bridge|INFO|bridge brv-1: added interface 
veth2 on port 2
2017-03-20T16:01:22.352Z|00001|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: CREATED -> VISIBLE
2017-03-20T16:01:22.352Z|00002|ofproto_dpif_upcall(handler32)|INFO|put 
count: 8
2017-03-20T16:01:22.352Z|00003|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.352Z|00004|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: CREATED -> VISIBLE
2017-03-20T16:01:22.352Z|00005|ofproto_dpif_upcall(handler32)|INFO|put 
count: 9
2017-03-20T16:01:22.352Z|00006|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.352Z|00007|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: CREATED -> VISIBLE
2017-03-20T16:01:22.353Z|00008|ofproto_dpif_upcall(handler32)|INFO|put 
count: 10
2017-03-20T16:01:22.353Z|00009|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.353Z|00010|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: CREATED -> VISIBLE
2017-03-20T16:01:22.353Z|00011|ofproto_dpif_upcall(handler32)|INFO|put 
count: 11
2017-03-20T16:01:22.353Z|00012|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: VISIBLE -> OPERATIONAL
2017-03-20T16:01:22.358Z|00001|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.358Z|00002|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.358Z|00003|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.358Z|00004|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.608Z|00001|ofproto_dpif_upcall(revalidator35)|INFO|revalidate 
2345 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.608Z|00002|ofproto_dpif_upcall(revalidator35)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.608Z|00003|ofproto_dpif_upcall(revalidator35)|INFO|revalidate 
2345 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.608Z|00004|ofproto_dpif_upcall(revalidator35)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.608Z|00005|ofproto_dpif_upcall(revalidator35)|INFO|revalidate 
2345 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.608Z|00006|ofproto_dpif_upcall(revalidator35)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.608Z|00007|ofproto_dpif_upcall(revalidator35)|INFO|revalidate 
2345 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:22.608Z|00008|ofproto_dpif_upcall(revalidator35)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> EVICTING
2017-03-20T16:01:22.608Z|00009|ofproto_dpif_upcall(revalidator35)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: EVICTING -> EVICTED
2017-03-20T16:01:22.608Z|00010|ofproto_dpif_upcall(revalidator35)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: EVICTING -> EVICTED
2017-03-20T16:01:22.608Z|00011|ofproto_dpif_upcall(revalidator35)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTING -> EVICTED
2017-03-20T16:01:22.608Z|00012|ofproto_dpif_upcall(revalidator35)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTING -> EVICTED
2017-03-20T16:01:22.608Z|00001|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTED -> DELETED
2017-03-20T16:01:22.608Z|00002|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:2ac65ff6-17a1-446e-be0a-6cf852981ee8: EVICTED -> DELETED
2017-03-20T16:01:22.608Z|00001|ofproto_dpif_upcall(revalidator37)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:0e45d246-f6c6-4b00-9e30-408643192b46: EVICTED -> DELETED
2017-03-20T16:01:22.609Z|00005|ofproto_dpif_upcall(revalidator33)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTED -> DELETED
2017-03-20T16:01:22.951Z|00013|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: CREATED -> VISIBLE
2017-03-20T16:01:22.951Z|00014|ofproto_dpif_upcall(handler32)|INFO|put 
count: 12
2017-03-20T16:01:22.951Z|00015|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: VISIBLE -> OPERATIONAL
2017-03-20T16:01:23.359Z|00006|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:23.359Z|00007|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: OPERATIONAL -> EVICTING
2017-03-20T16:01:23.359Z|00008|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: EVICTING -> EVICTED
2017-03-20T16:01:23.360Z|00002|ofproto_dpif_upcall(revalidator37)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:9009f598-48ca-4db1-aabc-8c6e5f25a648: EVICTED -> DELETED
2017-03-20T16:01:24.354Z|00016|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: CREATED -> VISIBLE
2017-03-20T16:01:24.354Z|00017|ofproto_dpif_upcall(handler32)|INFO|put 
count: 13
2017-03-20T16:01:24.354Z|00018|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: VISIBLE -> OPERATIONAL
2017-03-20T16:01:24.354Z|00019|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: CREATED -> VISIBLE
2017-03-20T16:01:24.354Z|00020|ofproto_dpif_upcall(handler32)|INFO|put 
count: 14
2017-03-20T16:01:24.354Z|00021|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: VISIBLE -> OPERATIONAL
2017-03-20T16:01:24.612Z|00009|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:24.612Z|00010|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> EVICTING
2017-03-20T16:01:24.612Z|00011|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:24.612Z|00012|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> EVICTING
2017-03-20T16:01:24.612Z|00013|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTING -> EVICTED
2017-03-20T16:01:24.612Z|00014|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTING -> EVICTED
2017-03-20T16:01:24.612Z|00003|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTED -> DELETED
2017-03-20T16:01:24.612Z|00015|ofproto_dpif_upcall(revalidator33)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTED -> DELETED
2017-03-20T16:01:25.575Z|00022|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: CREATED -> VISIBLE
2017-03-20T16:01:25.575Z|00023|ofproto_dpif_upcall(handler32)|INFO|put 
count: 15
2017-03-20T16:01:25.575Z|00024|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: VISIBLE -> OPERATIONAL
2017-03-20T16:01:25.864Z|00016|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:25.864Z|00017|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: OPERATIONAL -> EVICTING
2017-03-20T16:01:25.864Z|00018|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: EVICTING -> EVICTED
2017-03-20T16:01:25.865Z|00004|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:c59ccbff-eae6-4bed-82a5-89766add0fa1: EVICTED -> DELETED
2017-03-20T16:01:26.407Z|00025|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: CREATED -> VISIBLE
2017-03-20T16:01:26.407Z|00026|ofproto_dpif_upcall(handler32)|INFO|put 
count: 16
2017-03-20T16:01:26.407Z|00027|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: VISIBLE -> OPERATIONAL
2017-03-20T16:01:26.407Z|00028|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: CREATED -> VISIBLE
2017-03-20T16:01:26.407Z|00029|ofproto_dpif_upcall(handler32)|INFO|put 
count: 17
2017-03-20T16:01:26.407Z|00030|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: VISIBLE -> OPERATIONAL
2017-03-20T16:01:26.471Z|00031|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: CREATED -> VISIBLE
2017-03-20T16:01:26.471Z|00032|ofproto_dpif_upcall(handler32)|INFO|put 
count: 18
2017-03-20T16:01:26.471Z|00033|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: VISIBLE -> OPERATIONAL
2017-03-20T16:01:26.864Z|00019|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:26.864Z|00020|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: OPERATIONAL -> EVICTING
2017-03-20T16:01:26.864Z|00021|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:26.864Z|00022|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: OPERATIONAL -> EVICTING
2017-03-20T16:01:26.864Z|00023|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:26.864Z|00024|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: OPERATIONAL -> EVICTING
2017-03-20T16:01:26.864Z|00025|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTING -> EVICTED
2017-03-20T16:01:26.864Z|00026|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTING -> EVICTED
2017-03-20T16:01:26.864Z|00027|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: EVICTING -> EVICTED
2017-03-20T16:01:26.864Z|00005|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:13818e08-c773-4716-b8c6-59d1e781770f: EVICTED -> DELETED
2017-03-20T16:01:26.865Z|00028|ofproto_dpif_upcall(revalidator33)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:7871e4ec-7302-464a-80f5-efaec2e72cbe: EVICTED -> DELETED
2017-03-20T16:01:26.865Z|00006|ofproto_dpif_upcall(revalidator36)|INFO|ukey_delete 
1825 state transition for ukey 
ufid:b1d1717c-9523-4916-83d2-7e7da8e6b7bd: EVICTED -> DELETED
2017-03-20T16:01:27.495Z|00034|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:0e2a07df-cffd-46df-92aa-dd9f6baeae10: CREATED -> VISIBLE
2017-03-20T16:01:27.495Z|00035|ofproto_dpif_upcall(handler32)|INFO|put 
count: 19
2017-03-20T16:01:27.495Z|00036|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:0e2a07df-cffd-46df-92aa-dd9f6baeae10: VISIBLE -> OPERATIONAL
2017-03-20T16:01:27.495Z|00037|ofproto_dpif_upcall(handler32)|INFO|ukey_install__ 
1679 state transition for ukey 
ufid:e6cc74a9-bbdf-4d5d-a014-fec814f406c6: CREATED -> VISIBLE
2017-03-20T16:01:27.495Z|00038|ofproto_dpif_upcall(handler32)|INFO|put 
count: 20
2017-03-20T16:01:27.495Z|00039|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1414 sleeping 1/5 sec, ukey state: 1
2017-03-20T16:01:27.864Z|00029|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:0e2a07df-cffd-46df-92aa-dd9f6baeae10: OPERATIONAL -> OPERATIONAL
2017-03-20T16:01:27.864Z|00030|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:0e2a07df-cffd-46df-92aa-dd9f6baeae10: OPERATIONAL -> EVICTING
2017-03-20T16:01:27.864Z|00031|ofproto_dpif_upcall(revalidator33)|INFO|revalidate 
2345 state transition for ukey 
ufid:e6cc74a9-bbdf-4d5d-a014-fec814f406c6: VISIBLE -> OPERATIONAL
2017-03-20T16:01:27.864Z|00032|ofproto_dpif_upcall(revalidator33)|INFO|reval_op_init 
2245 state transition for ukey 
ufid:e6cc74a9-bbdf-4d5d-a014-fec814f406c6: OPERATIONAL -> EVICTING
2017-03-20T16:01:27.864Z|00033|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:0e2a07df-cffd-46df-92aa-dd9f6baeae10: EVICTING -> EVICTED
2017-03-20T16:01:27.864Z|00034|ofproto_dpif_upcall(revalidator33)|INFO|push_dp_ops 
2159 state transition for ukey 
ufid:e6cc74a9-bbdf-4d5d-a014-fec814f406c6: EVICTING -> EVICTED
2017-03-20T16:01:27.864Z|00007|ofproto_dpif_upcall(revalidator36)|INFO|sleeping
2017-03-20T16:01:27.864Z|00013|ofproto_dpif_upcall(revalidator35)|INFO|sleeping
2017-03-20T16:01:28.495Z|00040|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1414 sleeping 2/5 sec, ukey state: 4
2017-03-20T16:01:29.496Z|00041|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1414 sleeping 3/5 sec, ukey state: 4
2017-03-20T16:01:30.401Z|00054|memory|INFO|69400 kB peak resident set 
size after 10.1 seconds
2017-03-20T16:01:30.401Z|00055|memory|INFO|handlers:1 ports:3 
revalidators:5 rules:5 udpif keys:2
2017-03-20T16:01:30.496Z|00042|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1414 sleeping 4/5 sec, ukey state: 4
2017-03-20T16:01:31.496Z|00043|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1414 sleeping 5/5 sec, ukey state: 4
2017-03-20T16:01:32.496Z|00044|ofproto_dpif_upcall(handler32)|INFO|handle_upcalls 
1423 state transition for ukey 
ufid:e6cc74a9-bbdf-4d5d-a014-fec814f406c6: EVICTED -> OPERATIONAL
2017-03-20T16:01:32.496Z|00045|util(handler32)|EMER|ofproto/ofproto-dpif-upcall.c:1699: 
assertion dst >= ukey->state failed in transition_ukey()


##################END OF LOG ################



 From df02c4f769566ce6a8ebb8f228c9f3262c618395 Mon Sep 17 00:00:00 2001
From: Paul Blakey <paulb@mellanox.com>
Date: Sun, 19 Mar 2017 17:00:30 +0200
Subject: [PATCH] test

Change-Id: Iac752eb5fab3ff49da30a35bab3bee12673e1e28
---
  ofproto/ofproto-dpif-upcall.c | 55 
+++++++++++++++++++++++++++++++++----------
  1 file changed, 43 insertions(+), 12 deletions(-)

  static struct udpif_key *ukey_lookup(struct udpif *udpif,
                                       const ovs_u128 *ufid,
@@ -1399,15 +1401,30 @@ handle_upcalls(struct udpif *udpif, struct 
upcall *upcalls,
      dpif_operate(udpif->dpif, opsp, n_opsp);
      for (i = 0; i < n_ops; i++) {
          struct udpif_key *ukey = ops[i].ukey;
+        static int count = 0;
+        const int sleep_time = 5;
+        const int sleep_every_n_flows = 20;

          if (ukey) {
+            count++;
+            VLOG_INFO("put count: %d", count);
+            if ((count % sleep_every_n_flows) == 0) {
+                global_temp = 1;
+                for (int z = 0; z < sleep_time; z++) {
+                    VLOG_INFO("%s %d sleeping %d/%d sec, ukey state: 
%d",  __func__, __LINE__, z+1, sleep_time, ukey->state);
+                    xsleep(1);
+                }
+            }
+
              ovs_mutex_lock(&ukey->mutex);
              if (ops[i].dop.error) {
-                transition_ukey(ukey, UKEY_EVICTED);
+                transition_ukey(__func__, __LINE__, ukey, UKEY_EVICTED);
              } else {
-                transition_ukey(ukey, UKEY_OPERATIONAL);
+                transition_ukey(__func__, __LINE__, ukey, 
UKEY_OPERATIONAL);
              }
              ovs_mutex_unlock(&ukey->mutex);
+
+            global_temp = 0;
          }
      }
  }
@@ -1605,8 +1622,8 @@ try_ukey_replace(struct umap *umap, struct 
udpif_key *old_ukey,
              cmap_replace(&umap->cmap, &old_ukey->cmap_node,
                           &new_ukey->cmap_node, new_ukey->hash);
              ovsrcu_postpone(ukey_delete__, old_ukey);
-            transition_ukey(old_ukey, UKEY_DELETED);
-            transition_ukey(new_ukey, UKEY_VISIBLE);
+            transition_ukey(__func__, __LINE__, old_ukey, UKEY_DELETED);
+            transition_ukey(__func__, __LINE__, new_ukey, UKEY_VISIBLE);
              replaced = true;
          }
          ovs_mutex_unlock(&old_ukey->mutex);
@@ -1659,7 +1676,7 @@ ukey_install__(struct udpif *udpif, struct 
udpif_key *new_ukey)
      } else {
          ovs_mutex_lock(&new_ukey->mutex);
          cmap_insert(&umap->cmap, &new_ukey->cmap_node, new_ukey->hash);
-        transition_ukey(new_ukey, UKEY_VISIBLE);
+        transition_ukey(__func__, __LINE__, new_ukey, UKEY_VISIBLE);
          locked = true;
      }
      ovs_mutex_unlock(&umap->mutex);
@@ -1667,10 +1684,18 @@ ukey_install__(struct udpif *udpif, struct 
udpif_key *new_ukey)
      return locked;
  }

+char *state_to_str[] = { "CREATED", "VISIBLE", "OPERATIONAL", 
"EVICTING", "EVICTED", "DELETED" };
+
  static void
-transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
+transition_ukey(const char *func, int line, struct udpif_key *ukey, 
enum ukey_state dst)
      OVS_REQUIRES(ukey->mutex)
  {
+    struct ds ds2 = DS_EMPTY_INITIALIZER;
+
+    odp_format_ufid(&ukey->ufid, &ds2);
+    VLOG_INFO("%s %d state transition for ukey %s: %s -> %s", func, 
line, ds_cstr(&ds2), state_to_str[ukey->state], state_to_str[dst]);
+    ds_destroy(&ds2);
+
      ovs_assert(dst >= ukey->state);
      if (ukey->state == dst && dst == UKEY_OPERATIONAL) {
          return;
@@ -1797,7 +1822,7 @@ ukey_delete(struct umap *umap, struct udpif_key *ukey)
      if (ukey->state < UKEY_DELETED) {
          cmap_remove(&umap->cmap, &ukey->cmap_node, ukey->hash);
          ovsrcu_postpone(ukey_delete__, ukey);
-        transition_ukey(ukey, UKEY_DELETED);
+        transition_ukey(__func__, __LINE__, ukey, UKEY_DELETED);
      }
      ovs_mutex_unlock(&ukey->mutex);
  }
@@ -2131,7 +2156,7 @@ push_dp_ops(struct udpif *udpif, struct ukey_op 
*ops, size_t n_ops)

          if (op->ukey) {
              ovs_mutex_lock(&op->ukey->mutex);
-            transition_ukey(op->ukey, UKEY_EVICTED);
+            transition_ukey(__func__, __LINE__, op->ukey, UKEY_EVICTED);
              push->used = MAX(stats->used, op->ukey->stats.used);
              push->tcp_flags = stats->tcp_flags | 
op->ukey->stats.tcp_flags;
              push->n_packets = stats->n_packets - 
op->ukey->stats.n_packets;
@@ -2217,7 +2242,7 @@ reval_op_init(struct ukey_op *op, enum 
reval_result result,
  {
      if (result == UKEY_DELETE) {
          delete_op_init(udpif, op, ukey);
-        transition_ukey(ukey, UKEY_EVICTING);
+        transition_ukey(__func__, __LINE__, ukey, UKEY_EVICTING);
      } else if (result == UKEY_MODIFY) {
          /* Store the new recircs. */
          recirc_refs_swap(&ukey->recircs, recircs);
@@ -2317,7 +2342,7 @@ revalidate(struct revalidator *revalidator)
              }

              /* The flow is now confirmed to be in the datapath. */
-            transition_ukey(ukey, UKEY_OPERATIONAL);
+            transition_ukey(__func__, __LINE__, ukey, UKEY_OPERATIONAL);

              if (!used) {
                  used = ukey->created;
@@ -2417,6 +2442,12 @@ revalidator_sweep__(struct revalidator 
*revalidator, bool purge)
              ovs_mutex_unlock(&ukey->mutex);

              if (ukey_state == UKEY_EVICTED) {
+
+                while (global_temp) {
+                    VLOG_INFO("sleeping\n");
+                    xsleep(5);
+                }
+
                  /* The common flow deletion case involves deletion of 
the flow
                   * during the dump phase and ukey deletion here. */
                  ovs_mutex_lock(&umap->mutex);
@@ -2471,7 +2502,7 @@ dp_purge_cb(void *aux, unsigned pmd_id)
          CMAP_FOR_EACH(ukey, cmap_node, &umap->cmap) {
              if (ukey->pmd_id == pmd_id) {
                  delete_op_init(udpif, &ops[n_ops++], ukey);
-                transition_ukey(ukey, UKEY_EVICTING);
+                transition_ukey(__func__, __LINE__, ukey, UKEY_EVICTING);

                  if (n_ops == REVALIDATE_MAX_BATCH) {
                      push_ukey_ops(udpif, umap, ops, n_ops);
--
1.8.4.3
diff mbox

Patch

diff --git a/ofproto/ofproto-dpif-upcall.c b/ofproto/ofproto-dpif-upcall.c
index 660383f..3291219 100644
--- a/ofproto/ofproto-dpif-upcall.c
+++ b/ofproto/ofproto-dpif-upcall.c
@@ -45,6 +45,8 @@ 
  #define UPCALL_MAX_BATCH 64
  #define REVALIDATE_MAX_BATCH 50

+int global_temp = 0;
+
  VLOG_DEFINE_THIS_MODULE(ofproto_dpif_upcall);

  COVERAGE_DEFINE(dumped_duplicate_flow);
@@ -350,7 +352,7 @@  static void ukey_get_actions(struct udpif_key *, 
const struct nlattr **actions,
  static bool ukey_install__(struct udpif *, struct udpif_key *ukey)
      OVS_TRY_LOCK(true, ukey->mutex);
  static bool ukey_install(struct udpif *udpif, struct udpif_key *ukey);
-static void transition_ukey(struct udpif_key *ukey, enum ukey_state dst)
+static void transition_ukey(const char *func, int line, struct 
udpif_key *ukey, enum ukey_state dst)
      OVS_REQUIRES(ukey->mutex);