Agent crash due to failed concurreny check while freeing flow entry

root@sriov:~/var/log# cd coredump/
root@sriov:~/var/log/coredump# ls
core.contrail-vroute.24365.rdm5r16c015.rdm5b.cci.att.com.1504119226 core.contrail-vroute.37795.rdm5r16c015.rdm5b.cci.att.com.1504046049 core.contrail-vroute.5744.rdm5r16c015.rdm5b.cci.att.com.1504110311
core.contrail-vroute.34655.rdm5r16c015.rdm5b.cci.att.com.1504116100 core.contrail-vroute.41156.rdm5r16c015.rdm5b.cci.att.com.1504128467
root@sriov:~/var/log/coredump# date -d @1504119226
Wed Aug 30 11:53:46 PDT 2017
root@sriov:~/var/log/coredump# date -d @1504046049
Tue Aug 29 15:34:09 PDT 2017
root@sriov:~/var/log/coredump# date -d @1504110311
Wed Aug 30 09:25:11 PDT 2017
root@sriov:~/var/log/coredump# date -d @1504116100
Wed Aug 30 11:01:40 PDT 2017
root@sriov:~/var/log/coredump# date -d @1504128467
Wed Aug 30 14:27:47 PDT 2017
root@sriov:~/var/log/coredump#

root@sriov:~/var/log/coredump# strings core.contrail-vroute.37795.rdm5r16c015.rdm5b.cci.att.com.1504046049 | grep build-info
{"build-info": [{"build-time": "2017-06-29 09:59:25.240327", "build-hostname": "ubuntu", "build-user": "contrail-builder", "build-version": "3.2.3.2"}]}
{"build-info":[{"build-time":"2017-06-29 09:59:25.240327","build-hostname":"ubuntu","build-user":"contrail-builder","build-version":"3.2.3.2","build-id":"3.2.3.2-6","build-number":"6"}]}
{"build-infoA
{"build-info":[{"build-time":"2017-06-29 09:59:25.240327","build-hostname":"ubuntu","build-user":"contrail-builder","build-version":"3.2.3.2","build-id":"3.2.3.2-6","build-number":"6"}]}
{"build-info": [{"build-time": "2017-06-29 10:47:18.086620", "build-hostname": "ubuntu", "build-user": "contrail-builder", "build-version": "3.2.3.2"}]}
root@sriov:~/var/log/coredump# contrail-version
Package Version Build-ID | Repo | Package Name
-------------------------------------- ------------------------------ ----------------------------------
contrail-analytics 3.2.3.2-6 6
contrail-config 3.2.3.2-6 6
contrail-config-openstack 3.2.3.2-6 6
contrail-control 3.2.3.2-6 6
contrail-database-common 3.2.3.2-6 6
contrail-dns 3.2.3.2-6 6
contrail-docs 3.2.3.2-6 6
contrail-f5 3.2.3.2-6 6
contrail-fabric-utils 3.2.3.2-6 6
contrail-heat 3.2.3.2-6 6
contrail-install-packages 3.2.3.2-6~mitaka 6
contrail-lib 3.2.3.2-6 6
contrail-nodemgr 3.2.3.2-6 6
contrail-nova-netw...

Hi Hari, can you please have someone in your team to analyze this? Thank you so much.

#3 0x00007f133a6beca2 in __GI___assert_fail (assertion=0x13944d0 "table_->ConcurrencyCheck(table_->flow_task_id()) == true",
    file=0x1394448 "controller/src/vnsw/agent/pkt/flow_table.cc", line=919,
    function=0x1394940 <FlowEntryFreeList::Free(FlowEntry*)::__PRETTY_FUNCTION__> "void FlowEntryFreeList::Free(FlowEntry*)") at assert.c:101
#4 0x0000000000cec455 in FlowEntryFreeList::Free (this=this@entry=0x7f132c604a40, flow=flow@entry=0x7f1318e8f0c0) at controller/src/vnsw/agent/pkt/flow_table.cc:919
#5 0x0000000000cdd528 in intrusive_ptr_release (fe=0x7f1318e8f0c0) at controller/src/vnsw/agent/pkt/flow_entry.cc:497
#6 0x0000000000cf7199 in ~intrusive_ptr (this=0x7f1320438ae0, __in_chrg=<optimized out>) at /usr/include/boost/smart_ptr/intrusive_ptr.hpp:97
#7 ~FlowMgmtRequest (this=0x7f1320438ad0, __in_chrg=<optimized out>) at controller/src/vnsw/agent/pkt/flow_mgmt_request.h:68
#8 FlowMgmtRequest::~FlowMgmtRequest (this=0x7f1320438ad0, __in_chrg=<optimized out>) at controller/src/vnsw/agent/pkt/flow_mgmt_request.h:68
#9 0x000000000087bcce in boost::detail::sp_counted_base::release (this=0x7f1320841a30) at /usr/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:146
#10 0x0000000000cfd435 in ~shared_count (this=0x7f1333b27a58, __in_chrg=<optimized out>) at /usr/include/boost/smart_ptr/detail/shared_count.hpp:371
#11 ~shared_ptr (this=0x7f1333b27a50, __in_chrg=<optimized out>) at /usr/include/boost/smart_ptr/shared_ptr.hpp:328
#12 QueueTaskRunner<boost::shared_ptr<FlowMgmtRequest>, WorkQueue<boost::shared_ptr<FlowMgmtRequest> > >::RunQueue (this=0x7f1320605630) at controller/src/base/queue_task.h:108
#13 0x000000000130560f in TaskImpl::execute (this=0x7f1333cf3e40) at controller/src/base/task.cc:262

Waiting for this issue to be hit with an instrumented agent binary.

@Hari - As per Qasim this is not a valid configuration of using /16 for AAP for this VNF - vCTS. we need to let ATT know that /16 is not allowed for AAP.

Thanks
Sree

Review in progress for https://review.opencontrail.org/36224
Submitter: Naveen N (<email address hidden>)

Review in progress for https://review.opencontrail.org/36225
Submitter: Naveen N (<email address hidden>)

Reviewed: https://review.opencontrail.org/36224
Committed: http://github.com/Juniper/contrail-controller/commit/23f0ddaa2b26405fa368c38cfde9417386fd6e66
Submitter: Zuul (<email address hidden>)
Branch: R3.2

commit 23f0ddaa2b26405fa368c38cfde9417386fd6e66
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371

Review in progress for https://review.opencontrail.org/36244
Submitter: Naveen N (<email address hidden>)

Reviewed: https://review.opencontrail.org/36244
Committed: http://github.com/Juniper/contrail-controller/commit/a0cb1666537424d81d6989e87c781f241d9ef41b
Submitter: Zuul (<email address hidden>)
Branch: R4.0

commit a0cb1666537424d81d6989e87c781f241d9ef41b
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371

Review in progress for https://review.opencontrail.org/36408
Submitter: Hari Prasad Killi (<email address hidden>)

Reviewed: https://review.opencontrail.org/36408
Committed: http://github.com/Juniper/contrail-controller/commit/b9773f1187249b041fa490dd1eaf1080e9a4dda7
Submitter: Zuul (<email address hidden>)
Branch: R4.1

commit b9773f1187249b041fa490dd1eaf1080e9a4dda7
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371
(cherry picked from commit a0cb1666537424d81d6989e87c781f241d9ef41b)

Review in progress for https://review.opencontrail.org/36447
Submitter: Naveen N (<email address hidden>)

Reviewed: https://review.opencontrail.org/36447
Committed: http://github.com/Juniper/contrail-controller/commit/4bcecc0547f5886bf0a3c8645817437d87d312e4
Submitter: Zuul (<email address hidden>)
Branch: master

commit 4bcecc0547f5886bf0a3c8645817437d87d312e4
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371
(cherry picked from commit a0cb1666537424d81d6989e87c781f241d9ef41b)

Review in progress for https://review.opencontrail.org/36829
Submitter: Hari Prasad Killi (<email address hidden>)

Reviewed: https://review.opencontrail.org/36829
Committed: http://github.com/Juniper/contrail-controller/commit/1754efe51606c68aafba8ce06d280a95247c7816
Submitter: Zuul (<email address hidden>)
Branch: R3.1

commit 1754efe51606c68aafba8ce06d280a95247c7816
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371
(cherry picked from commit 23f0ddaa2b26405fa368c38cfde9417386fd6e66)

Based on the theory that eviction and delete dont run in parallel in R3.0.3, not picking this fix for that branch.

Reviewed: https://review.opencontrail.org/36225
Committed: http://github.com/Juniper/contrail-controller/commit/bba3d9c87beb51b00e482eeb8a0f51e2d7916a50
Submitter: Zuul (<email address hidden>)
Branch: R3.2.3.x

commit bba3d9c87beb51b00e482eeb8a0f51e2d7916a50
Author: Naveen N <email address hidden>
Date: Wed Oct 4 16:08:26 2017 +0530

* Read reverse flow entry after acquiring the lock

In case of short lived TCP session using same 5 tuple we might
end up accesssing a reverse flow entry which might be already deleted
and present in free list. Below set of events lead to this issue

1. F1 and R1 flow are added to flow table
2. R1 is written to vrouter
3. F1 is written to vrouter
4. R1 flow add response is received, triggering update of
F1(not needed now as reverse flow index is not written to
kernel?)
5. In the meantime flow is evicted in vrouter, hence flow
update for F1 would result in error from vrouter resulting in short flow
6. Since F1 is shortflow Flow delete gets enqueued
7. Since R1 is evict marked, flow evict gets enqueued
8. Both event F1 and R1 delete and evict event can run in
parallel,and hence reverse flow pointer obtained before FLOW
lock could be invalid, hence read back the same

Was able to simulate the same in UT, UT is disabled as it need some
instrumentation to run it to hit the issue

Change-Id: I368f465f9d446b43dfe0e4baa547d8c8cbfd6840
Closes-bug: #1714371