Merge lp:~michihenning/unity-scopes-api/fix-leak-and-warnings into lp:unity-scopes-api

[Michi Henning]

Fixed memory leak in BufferedResultForwarder. Fixed a bunch of
warnings for clang build. Minor updates to HACKING.

During the tests for revision 282, we got a core dump from the smartscopesproxy test.

The core dump was caused by rapid startup and shutdown of the RuntimeImpl instances used by the smartscopesproxy test. That allowed a zmq endpoint to linger behind after the previous RuntimeImpl was destroyed, causing the next RuntimeImpl to throw because the endpoint was still bound. (zmq context destruction is asynchronous, unfortunately.) In turn, that exposed a life cycle issue where ZmqMiddleware was calling into an already-destroyed logger instance, because the signal handlers in the registry and smartscopes registry were keeping the ZmqMiddleware instance alive beyond the life time of the RuntimeImpl.

Solution was two-fold:

- Don't log from the ZmqMiddleware destructor. No information is lost because the same exception information is provided by wait_for_shutdown(), and RuntimeImpl logs that anyway.

 - Added 300 ms delay to the smartscopesproxy test when the runtime is destroyed. This gives zmq time to close its server sockets, so we don't get a double-bind failure.

Fixed memory leak in BufferedResultForwarder. Fixed a bunch of
warnings for clang build. Minor updates to HACKING.

During the tests for revision 282, we got a core dump from the smartscopesproxy test.

The core dump was caused by rapid startup and shutdown of the RuntimeImpl instances used by the smartscopesproxy test. That allowed a zmq endpoint to linger behind after the previous RuntimeImpl was destroyed, causing the next RuntimeImpl to throw because the endpoint was still bound. (zmq context destruction is asynchronous, unfortunately.) In turn, that exposed a life cycle issue where ZmqMiddleware was calling into an already-destroyed logger instance, because the signal handlers in the registry and smartscopes registry were keeping the ZmqMiddleware instance alive beyond the life time of the RuntimeImpl.

Solution was two-fold:

- Don't log from the ZmqMiddleware destructor. No information is lost because the same exception information is provided by wait_for_shutdown(), and RuntimeImpl logs that anyway.

 - Added 300 ms delay to the smartscopesproxy test when the runtime is destroyed. This gives zmq time to close its server sockets, so we don't get a double-bind failure.

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:281
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-ci/546/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-amd64-ci/73
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/71
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/71/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-i386-ci/72

Click here to trigger a rebuild:
http://s-jenkins.ubuntu-ci:8080/job/unity-scopes-api-ci/546/rebuild

review: Approve (continuous-integration)

[Paweł Stołowski (stolowski)]

Oh gosh, great catch with the mem leak, thanks!

review: Approve

[Michi Henning (michihenning)]

Top-approving myself after fixing typo in HACKING.

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:282
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-ci/547/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-amd64-ci/74/console
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/72
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/72/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-i386-ci/73

Click here to trigger a rebuild:
http://s-jenkins.ubuntu-ci:8080/job/unity-scopes-api-ci/547/rebuild

review: Needs Fixing (continuous-integration)

[lp:~michihenning/unity-scopes-api/fix-leak-and-warnings]

285. By Michi Henning on 2015-01-23

Removed call to boost log from ZmqMiddleware destructor.

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:284
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-ci/548/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-amd64-ci/75
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/73
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/73/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-i386-ci/74

Click here to trigger a rebuild:
http://s-jenkins.ubuntu-ci:8080/job/unity-scopes-api-ci/548/rebuild

review: Approve (continuous-integration)

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:285
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-ci/549/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-amd64-ci/76
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/74
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-armhf-ci/74/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-vivid-i386-ci/75

Click here to trigger a rebuild:
http://s-jenkins.ubuntu-ci:8080/job/unity-scopes-api-ci/549/rebuild

review: Approve (continuous-integration)

=== modified file 'HACKING'
--- HACKING	2015-01-06 01:05:48 +0000
+++ HACKING	2015-01-23 05:01:22 +0000
@@ -61,12 +61,7 @@
     $ make test
     $ make coverage
 
-Note that, with gcc 4.7.2 and cmake 2.8.10, you may get a bunch of
-warnings. To fix this, you can build cmake 2.8.10 with the following patch:
-
-http://cmake.org/gitweb?p=cmake.git;a=commitdiff;h=61ace1df2616e472d056b302e4269cbf112fb020#patch1
-
-Unfortunately, it is not possibly to get 100% coverage for some files,
+Unfortunately, it is not possible to get 100% coverage for some files,
 mainly due to gcc's generation of two destructors for dynamic and non-
 dynamic instances. For abstract base classes and for classes that
 prevent stack and static allocation, this causes one of the destructors
@@ -85,7 +80,8 @@
 
     $ make clean-coverage
 
-This deletes all the .gcda files, allowing the merge to succeed again.
+This deletes all the .gcda files, allowing the merge to (sometimes) succeed again.
+If this doesn't work either, the only remedy is to do a clean build.
 
 If lcov complains about unrecognized lines involving '=====',
 you can patch geninfo and gcovr as explained here:
@@ -102,13 +98,21 @@
 We use a format tool that fixes a whole lot of issues
 regarding code style. The formatting changes made by
 the tool are generally sensible (even though they may not be your
-personal preference in all case). If there is a case where the formatting
+personal preference in all cases). If there is a case where the formatting
 really messes things up, consider re-arranging the code to avoid the problem.
 The convenience of running the entire code base through the pretty-printer
 far outweighs any minor glitches with pretty printing, and it means that
 we get consistent code style for free, rather than endlessly having to
 watch out for formatting issues during code reviews.
 
+As of clang-format-3.7, you can use
+
+    // clang-format off
+    void    unformatted_code  ;
+    // clang-format on
+
+to suppress formatting for a section of code.
+
 To format specific files:
 
     ${CMAKE_BINARY_DIR}/tools/formatcode x.cpp x.h

=== modified file 'include/unity/scopes/internal/QueryCtrlObjectBase.h'
--- include/unity/scopes/internal/QueryCtrlObjectBase.h	2015-01-09 00:14:14 +0000
+++ include/unity/scopes/internal/QueryCtrlObjectBase.h	2015-01-23 05:01:22 +0000
@@ -29,7 +29,7 @@
 namespace internal
 {
 
-class InvokeInfo;
+struct InvokeInfo;
 
 class QueryCtrlObjectBase : public AbstractObject
 {

=== modified file 'include/unity/scopes/internal/QueryObjectBase.h'
--- include/unity/scopes/internal/QueryObjectBase.h	2015-01-09 00:14:14 +0000
+++ include/unity/scopes/internal/QueryObjectBase.h	2015-01-23 05:01:22 +0000
@@ -31,7 +31,7 @@
 namespace internal
 {
 
-class InvokeInfo;
+struct InvokeInfo;
 
 class QueryObjectBase : public AbstractObject
 {

=== modified file 'include/unity/scopes/internal/ReplyObject.h'
--- include/unity/scopes/internal/ReplyObject.h	2015-01-09 00:14:14 +0000
+++ include/unity/scopes/internal/ReplyObject.h	2015-01-23 05:01:22 +0000
@@ -35,7 +35,7 @@
 namespace internal
 {
 
-class InvokeInfo;
+struct InvokeInfo;
 class RuntimeImpl;
 
 // A ReplyObject sits in between the incoming requests from the middleware layer and the

=== modified file 'include/unity/scopes/internal/ScopeObjectBase.h'
--- include/unity/scopes/internal/ScopeObjectBase.h	2015-01-09 00:14:14 +0000
+++ include/unity/scopes/internal/ScopeObjectBase.h	2015-01-23 05:01:22 +0000
@@ -38,7 +38,7 @@
 namespace internal
 {
 
-class InvokeInfo;
+struct InvokeInfo;
 
 class ScopeObjectBase : public AbstractObject
 {

=== modified file 'include/unity/scopes/internal/smartscopes/SmartScopesClient.h'
--- include/unity/scopes/internal/smartscopes/SmartScopesClient.h	2015-01-09 03:16:51 +0000
+++ include/unity/scopes/internal/smartscopes/SmartScopesClient.h	2015-01-23 05:01:22 +0000
@@ -229,7 +229,6 @@
 
     HttpClientInterface::SPtr http_client_;
     JsonNodeInterface::SPtr json_node_;
-    RuntimeImpl* runtime_;
     boost::log::sources::severity_channel_logger_mt<>& logger_;
     std::string url_;
 

=== modified file 'include/unity/scopes/utility/BufferedResultForwarder.h'
--- include/unity/scopes/utility/BufferedResultForwarder.h	2014-12-01 01:51:38 +0000
+++ include/unity/scopes/utility/BufferedResultForwarder.h	2015-01-23 05:01:22 +0000
@@ -46,6 +46,8 @@
     /// @cond
     NONCOPYABLE(BufferedResultForwarder);
     UNITY_DEFINES_PTRS(BufferedResultForwarder);
+
+    virtual ~BufferedResultForwarder();
     /// @endcond
 
     /**
@@ -56,8 +58,8 @@
     \param next_forwarder The forwarder that becomes ready once this forwarder calls set_ready().
     \throws unity::LogicException when passed next_forwarder that has already been linked to another BufferedResultForwarder.
     */
-    BufferedResultForwarder(unity::scopes::SearchReplyProxy const& upstream, BufferedResultForwarder::SPtr const& next_forwarder =
-            BufferedResultForwarder::SPtr());
+    BufferedResultForwarder(unity::scopes::SearchReplyProxy const& upstream,
+                            BufferedResultForwarder::SPtr const& next_forwarder = BufferedResultForwarder::SPtr());
 
     /**
     \brief Forwards a single result before calling `set_ready()`.
@@ -104,7 +106,7 @@
 private:
     friend class internal::BufferedResultForwarderImpl;
 
-    internal::BufferedResultForwarderImpl *p;
+    std::unique_ptr<internal::BufferedResultForwarderImpl> p;
 };
 
 } // namespace utility

=== modified file 'scoperegistry/scoperegistry.cpp'
--- scoperegistry/scoperegistry.cpp	2015-01-09 03:16:51 +0000
+++ scoperegistry/scoperegistry.cpp	2015-01-23 05:01:22 +0000
@@ -527,7 +527,7 @@
         // And finally creating our runtime.
         string identity;
         string ss_reg_id;
-        RuntimeImpl::UPtr runtime;
+        RuntimeImpl::SPtr runtime;
         {
             RuntimeConfig rt_config(config_file);
             runtime = RuntimeImpl::create(rt_config.registry_identity(), config_file);
@@ -576,18 +576,16 @@
             process_timeout = c.process_timeout();
         } // Release memory for config parser
 
-        MiddlewareBase::SPtr middleware = runtime->factory()->find(identity, mw_kind);
-
-        // Inform the signal thread that it should shutdown the middleware
+        // Inform the signal thread that it should shutdown the runtime
         // if we get a termination signal.
-        signal_handler_wrapper.signal_raised().connect([middleware](core::posix::Signal signal)
+        signal_handler_wrapper.signal_raised().connect([runtime](core::posix::Signal signal)
         {
             switch(signal)
             {
             case core::posix::Signal::sig_int:
             case core::posix::Signal::sig_hup:
             case core::posix::Signal::sig_term:
-                middleware->stop();
+                runtime->destroy();
                 break;
             default:
                 break;
@@ -595,6 +593,7 @@
         });
 
         // The registry object stores the local and remote scopes
+        MiddlewareBase::SPtr middleware = runtime->factory()->find(identity, mw_kind);
         Executor::SPtr executor = std::make_shared<Executor>();
         RegistryObject::SPtr registry(new RegistryObject(*signal_handler_wrapper.death_observer, executor, middleware, true));
 

=== modified file 'smartscopesproxy/smartscopesproxy.cpp'
--- smartscopesproxy/smartscopesproxy.cpp	2014-07-04 03:26:15 +0000
+++ smartscopesproxy/smartscopesproxy.cpp	2015-01-23 05:01:22 +0000
@@ -116,7 +116,7 @@
         std::string ss_scope_id = ss_config.scope_identity();
 
         // Instantiate the run time
-        RuntimeImpl::UPtr rt = RuntimeImpl::create(ss_reg_id, config_file);
+        RuntimeImpl::SPtr rt = RuntimeImpl::create(ss_reg_id, config_file);
 
         // Get registry config
         RegistryConfig reg_conf(ss_reg_id, rt->registry_configfile());
@@ -125,11 +125,13 @@
         // Get middleware handle from runtime
         MiddlewareBase::SPtr mw = rt->factory()->find(ss_reg_id, mw_kind);
 
-        signal_handler.signal_raised().connect([mw](core::posix::Signal)
+        signal_handler.signal_raised().connect([rt](core::posix::Signal)
         {
-            mw->stop();
+            rt->destroy();
         });
 
+        MiddlewareBase::SPtr middleware = rt->factory()->find(ss_reg_id, mw_kind);
+
         // Instantiate a SS registry object
         SSRegistryObject::SPtr reg(new SSRegistryObject(mw, ss_config, mw->get_scope_endpoint()));
 

=== modified file 'src/scopes/internal/Logger.cpp'
--- src/scopes/internal/Logger.cpp	2015-01-18 23:48:55 +0000
+++ src/scopes/internal/Logger.cpp	2015-01-23 05:01:22 +0000
@@ -51,7 +51,7 @@
 
 static array<string, Logger::LastChannelEnum_> const channel_names =
     {
-        "IPC"
+        { "IPC" }
     };
 
 string const& to_severity(int s)

=== modified file 'src/scopes/internal/smartscopes/SmartScopesClient.cpp'
--- src/scopes/internal/smartscopes/SmartScopesClient.cpp	2015-01-09 03:16:51 +0000
+++ src/scopes/internal/smartscopes/SmartScopesClient.cpp	2015-01-23 05:01:22 +0000
@@ -116,7 +116,6 @@
                                      std::string const& partner_id_path)
     : http_client_(http_client)
     , json_node_(json_node)
-    , runtime_(runtime)
     , logger_(runtime ? runtime->logger() : test_logger::get())
     , have_latest_cache_(false)
     , query_counter_(0)

=== modified file 'src/scopes/internal/zmq_middleware/ZmqMiddleware.cpp'
--- src/scopes/internal/zmq_middleware/ZmqMiddleware.cpp	2015-01-09 03:16:51 +0000
+++ src/scopes/internal/zmq_middleware/ZmqMiddleware.cpp	2015-01-23 05:01:22 +0000
@@ -160,24 +160,27 @@
         // Until we figure out what's going on here, we measure
         // how long it takes and print a warning if it takes
         // longer than 100 ms.
+        //
+        // Update: This happens only when build nodes on
+        // Jenkins are ridiculously slow. Leaving the
+        // diagnostic in place for the time being, which
+        // helps with realizing when something isn't working
+        // right on Jenkins.
         auto start_time = chrono::system_clock::now();
         context_.terminate();
         auto end_time = chrono::system_clock::now();
         auto millisecs = chrono::duration_cast<chrono::milliseconds>(end_time - start_time).count();
         if (millisecs > 100)
         {
-            BOOST_LOG(logger_)
-                << "warning: ~ZmqMiddleware(): context_.terminate() took " << millisecs
-                << " ms to complete for " << server_name_;
+            cerr << "warning: ~ZmqMiddleware(): context_.terminate() took " << millisecs
+                 << " ms to complete for " << server_name_ << endl;
         }
     }
-    catch (std::exception const& e)
-    {
-        BOOST_LOG(logger_) << "~ZmqMiddleware(): " << e.what();
-    }
     catch (...)
     {
-        BOOST_LOG(logger_) << "~ZmqMiddleware(): unknown exception";
+        // Don't log here. RuntimeImpl does that after calling wait_for_shutdown().
+        // We may no longer have a logger here if something holds the middleware
+        // in scope beyond the life time of the runtime.
     }
 }
 

=== modified file 'src/scopes/utility/BufferedResultForwarder.cpp'
--- src/scopes/utility/BufferedResultForwarder.cpp	2014-11-27 17:03:10 +0000
+++ src/scopes/utility/BufferedResultForwarder.cpp	2015-01-23 05:01:22 +0000
@@ -129,6 +129,10 @@
 {
 }
 
+/// @cond
+BufferedResultForwarder::~BufferedResultForwarder() = default;
+/// @endcond
+
 bool BufferedResultForwarder::is_ready() const
 {
     return p->is_ready();

=== modified file 'test/gtest/scopes/internal/smartscopes/smartscopesproxy/smartscopesproxy_test.cpp'
--- test/gtest/scopes/internal/smartscopes/smartscopesproxy/smartscopesproxy_test.cpp	2014-12-03 06:53:40 +0000
+++ test/gtest/scopes/internal/smartscopes/smartscopesproxy/smartscopesproxy_test.cpp	2015-01-23 05:01:22 +0000
@@ -88,6 +88,11 @@
     ~smartscopesproxytest()
     {
         rt_->destroy();
+        // zmq shutdown is asynchronous and, if we don't wait,
+        // the next RuntimeImpl instance that is created may
+        // fail because the zmq endpoints may not have been unlinked
+        // in the filesystem yet.
+        std::this_thread::sleep_for(std::chrono::milliseconds(300));
     }
 
 protected: