Deleted trace message still accessed in generated trace message write call

[Ananth Suryanarayana]

As seen in the following trace, after the raceBuffer<SandeshTrace>::TraceWrite(), looks like before the caller function is completed, the buffer can get deleted (possibly because the buffer got filled from other threads, there by deleting this just inserted entry ?)

We should write message to the buffer as the last operation and do not touch the message afterwards..

diff --git a/compiler/generate/t_cpp_generator.cc b/compiler/generate/t_cpp_generator.cc
index 2c656b5..6b526cb 100755
--- a/compiler/generate/t_cpp_generator.cc
+++ b/compiler/generate/t_cpp_generator.cc
@@ -4430,9 +4430,9 @@ void t_cpp_generator::generate_sandesh_trace(ofstream& out,
             generate_sandesh_no_static_const_string_function(tsandesh, false, false, false, false, true) <<
             ";" << endl;
     out << indent() << creator_name << "->set_category(trace_buf->Name());" << endl;
- out << indent() << "uint32_t seqnum = trace_buf->TraceWrite(" << creator_name << ");" << endl;
     out << indent() << creator_name << "->set_seqnum(seqnum);" << endl;
     out << indent() << "if ((IsLocalLoggingEnabled() && IsTracePrintEnabled()) || IsUnitTest()) " << creator_name << "->Log();" << endl;
+ out << indent() << "uint32_t seqnum = trace_buf->TraceWrite(" << creator_name << ");" << endl;
     indent_down();
     out << indent() << "}" <<endl;
     indent_down();

==26776== Invalid write of size 4
==26776== at 0x5B016C: set_seqnum (sandesh.h:491)
==26776== by 0x5B016C: RprReplicate::TraceMsg(boost::shared_ptr<TraceBuffer<SandeshTrace> >, std::string, int, std::string, std::string, std::string, std::string, std::string, std::string) (routing_instance_analytics_types.cpp:9936)
==26776== by 0x614E03: RoutePathReplicator::RouteListener(TableState*, DBTablePartBase*, DBEntryBase*) (routepath_replicator.cc:591)
==26776== by 0xC9D959: operator() (function_template.hpp:767)
==26776== by 0xC9D959: RunNotify (db_table.cc:115)
==26776== by 0xC9D959: DBTableBase::RunNotify(DBTablePartBase*, DBEntryBase*) (db_table.cc:207)
==26776== by 0xC9FF37: DBTablePartBase::RunNotify() (db_table_partition.cc:47)
==26776== by 0xC9BDAD: DBPartition::QueueRunner::Run() (db_partition.cc:215)
==26776== by 0x6AD0DE: TaskImpl::execute() (task.cc:262)
==26776== by 0x670EB39: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x670A815: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x6709F4A: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x67060FE: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x67062F8: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x64D8183: start_thread (pthread_create.c:312)
==26776== by 0x744437C: clone (clone.S:111)
==26776== Address 0x1d461b18 is 72 bytes inside a block of size 152 free'd
==26776== at 0x4C2C2BC: operator delete(void*) (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
==26776== by 0x5CF3E9: RprReplicate::~RprReplicate() (routing_instance_analytics_types.h:4233)
==26776== by 0x574ADF: checked_delete<const SandeshTrace> (checked_delete.hpp:34)
==26776== by 0x574ADF: delete_clone<SandeshTrace> (clone_allocator.hpp:56)
==26776== by 0x574ADF: deallocate_clone<SandeshTrace> (clone_allocator.hpp:74)
==26776== by 0x574ADF: deallocate_clone (reversible_ptr_container.hpp:126)
==26776== by 0x574ADF: operator()<SandeshTrace> (reversible_ptr_container.hpp:57)
==26776== by 0x574ADF: ~static_move_ptr (static_move_ptr.hpp:85)
==26776== by 0x574ADF: push_back (ptr_circular_buffer.hpp:293)
==26776== by 0x574ADF: TraceBuffer<SandeshTrace>::TraceWrite(SandeshTrace*) (trace.h:61)
==26776== by 0x5B0164: RprReplicate::TraceMsg(boost::shared_ptr<TraceBuffer<SandeshTrace> >, std::string, int, std::string, std::string, std::string, std::string, std::string, std::string) (routing_instance_analytics_types.cpp:9935)
==26776== by 0x614E03: RoutePathReplicator::RouteListener(TableState*, DBTablePartBase*, DBEntryBase*) (routepath_replicator.cc:591)
==26776== by 0xC9D959: operator() (function_template.hpp:767)
==26776== by 0xC9D959: RunNotify (db_table.cc:115)
==26776== by 0xC9D959: DBTableBase::RunNotify(DBTablePartBase*, DBEntryBase*) (db_table.cc:207)
==26776== by 0xC9FF37: DBTablePartBase::RunNotify() (db_table_partition.cc:47)
==26776== by 0xC9BDAD: DBPartition::QueueRunner::Run() (db_partition.cc:215)
==26776== by 0x6AD0DE: TaskImpl::execute() (task.cc:262)
==26776== by 0x670EB39: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x670A815: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x6709F4A: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x67060FE: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x67062F8: ??? (in /usr/lib/libtbb.so.2)
==26776== by 0x64D8183: start_thread (pthread_create.c:312)
==26776== by 0x744437C: clone (clone.S:111)
==26776==

[OpenContrail Admin (ci-admin-f)]

Review in progress for https://review.opencontrail.org/22594
Submitter: Megh Bhatt (<email address hidden>)

[OpenContrail Admin (ci-admin-f)]

Review in progress for https://review.opencontrail.org/22595
Submitter: Megh Bhatt (<email address hidden>)

[OpenContrail Admin (ci-admin-f)]

Reviewed: https://review.opencontrail.org/22595
Committed: http://github.org/Juniper/contrail-sandesh/commit/de7cdadc89a1d067bb3f6c34ac42c244fa8c7ac4
Submitter: Zuul
Branch: master

commit de7cdadc89a1d067bb3f6c34ac42c244fa8c7ac4
Author: Megh Bhatt <email address hidden>
Date: Thu Jul 28 16:37:22 2016 -0700

Prevent access after free of trace messages

Add a GetNextSeqNum() function and call it to set the sequence
number in the trace message before calling TraceWrite().

Change-Id: I232e1134f711f534c166c18357986b8d1e692d15
Closes-Bug: #1602899

[OpenContrail Admin (ci-admin-f)]

Reviewed: https://review.opencontrail.org/22594
Committed: http://github.org/Juniper/contrail-controller/commit/d178741eff1b9d6f6a6ceb7d620bb76163322b64
Submitter: Zuul
Branch: master

commit d178741eff1b9d6f6a6ceb7d620bb76163322b64
Author: Megh Bhatt <email address hidden>
Date: Thu Jul 28 16:34:38 2016 -0700

Prevent access after free of trace messages

Add a GetNextSeqNum() function and call it to set the sequence
number in the trace message before calling TraceWrite().

Change-Id: I2d71e63421f5732648d40da69f1b5e65e520950d
Partial-Bug: #1602899