Merge lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages into lp:unity-scopes-api/devel

[Marcus Tomlinson]

Execute SDK DBus callback on scope start and stop in debug mode.

[lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages]

469. By Marcus Tomlinson on 2014-08-25

Whoops, reverted intentional break

470. By Marcus Tomlinson on 2014-08-25

Fixed formatting

[Paweł Stołowski (stolowski)]

91 + std::string started_message = "dbus-send --type=method_call --dest=com.ubuntu.SDKAppLaunch "
92 + "/ScopeRegistryCallback com.ubuntu.SDKAppLaunch.ScopeLoaded "
93 + "string:" + exec_data_.scope_id + " "
94 + "uint64:" + std::to_string(process_.pid());
95 + if (std::system(started_message.c_str()) != 0)

I think dbus-send by default would block for up to 25 seconds waiting for reply if there is a problemwith receiver; is registry going to block for that long then?

review: Needs Information

[Marcus Tomlinson (marcustomlinson)]

> 91 + std::string started_message = "dbus-send --type=method_call
> --dest=com.ubuntu.SDKAppLaunch "
> 92 + "/ScopeRegistryCallback com.ubuntu.SDKAppLaunch.ScopeLoaded "
> 93 + "string:" + exec_data_.scope_id + " "
> 94 + "uint64:" + std::to_string(process_.pid());
> 95 + if (std::system(started_message.c_str()) != 0)
>
> I think dbus-send by default would block for up to 25 seconds waiting for
> reply if there is a problemwith receiver; is registry going to block for that
> long then?

The remote methods being called are void methods, no return values. I've tried dbus-send without the service running and it returns immediately. I then put a 20s sleep in the callback method on the python side, and the dbus-send still returns immediately. So looks like we're fine

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:470
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-ci/1127/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-amd64-ci/685/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/680/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-i386-ci/679/console

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

review: Needs Fixing (continuous-integration)

[lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages]

471. By Marcus Tomlinson on 2014-08-25

Updated symbols

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:471
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-ci/1128/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-amd64-ci/686
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/681
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/681/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-i386-ci/680

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

review: Approve (continuous-integration)

[Paweł Stołowski (stolowski)]

Looks good, I've just one request: could you move the arguments of dbus-send calls into const strings somewhere, preferably at the top of the source file?

review: Needs Fixing

[Michi Henning (michihenning)]

93 + if (scope_started)
...
113 + else if (scope_started == false)

A simple "else" would do.

28 + void publish_state_change(bool scope_started);

Maybe use an enum Started, Stopped here? This would make the code at the call site much easier to read:

    publish_state_change(Started)

instead of

    publish_state_change(true);

if (std::system(started_message.c_str()) != 0)

This looks like a crash or a hang waiting to happen.

system() is not thread-safe. If we ever end up here concurrently (which is possible, I believe), we'll have a problem. I think it's necessary to serialise all calls to system.

review: Needs Fixing

[Michi Henning (michihenning)]

109 + std::cerr << "RegistryObject::ScopeProcess::publish_state_change(): Failed to execute SDK DBus callback" << endl;

It would be nice to have at least the scope ID in the error message (same with the exception a few lines below).

review: Needs Fixing

[Michi Henning (michihenning)]

I just noticed that there is also a call to system() in SSRegistryObject. I don't think we ever have both RegistryObject and SSRegistryObject instantiated in the same process, so we can't race there. But this suggests that we probably should have a utility class that wraps calls to system so they are serialised.

[lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages]

472. By Marcus Tomlinson on 2014-08-26

Addressed review comments

[Marcus Tomlinson (marcustomlinson)]

> Looks good, I've just one request: could you move the arguments of dbus-send
> calls into const strings somewhere, preferably at the top of the source file?

done

[Marcus Tomlinson (marcustomlinson)]

> 93 + if (scope_started)
> ...
> 113 + else if (scope_started == false)
>
> A simple "else" would do.
>
> 28 + void publish_state_change(bool scope_started);
>
> Maybe use an enum Started, Stopped here? This would make the code at the call
> site much easier to read:
>
> publish_state_change(Started)
>
> instead of
>
> publish_state_change(true);

done

>
> if (std::system(started_message.c_str()) != 0)
>
> This looks like a crash or a hang waiting to happen.
>
> system() is not thread-safe. If we ever end up here concurrently (which is
> possible, I believe), we'll have a problem. I think it's necessary to
> serialise all calls to system.

[Marcus Tomlinson (marcustomlinson)]

> 109 + std::cerr <<
> "RegistryObject::ScopeProcess::publish_state_change(): Failed to execute SDK
> DBus callback" << endl;
>
> It would be nice to have at least the scope ID in the error message (same with
> the exception a few lines below).

done

[Marcus Tomlinson (marcustomlinson)]

> I just noticed that there is also a call to system() in SSRegistryObject. I
> don't think we ever have both RegistryObject and SSRegistryObject instantiated
> in the same process, so we can't race there. But this suggests that we
> probably should have a utility class that wraps calls to system so they are
> serialised.

done

[lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages]

473. By Marcus Tomlinson on 2014-08-26

Move mutex into safe_system_call

[Michi Henning (michihenning)]

Looks good to me now, thanks!

review: Approve

[Marcus Tomlinson (marcustomlinson)]

> Looks good to me now, thanks!

Thank you for the thorough review :)

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:472
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-ci/1129/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-amd64-ci/687/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/682/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-i386-ci/681/console

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

review: Needs Fixing (continuous-integration)

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:473
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-ci/1130/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-amd64-ci/688/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/683/console
    FAILURE: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-i386-ci/682/console

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

review: Needs Fixing (continuous-integration)

[lp:~marcustomlinson/unity-scopes-api/debug_dbus_messages]

474. By Marcus Tomlinson on 2014-08-26

Updated symbols

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:474
http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-ci/1131/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-amd64-ci/689
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/684
        deb: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-armhf-ci/684/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/unity-scopes-api-devel-utopic-i386-ci/683

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

review: Approve (continuous-integration)

[Paweł Stołowski (stolowski)]

Thanks, LGTM!

review: Approve

=== modified file 'debian/libunity-scopes3.symbols'
--- debian/libunity-scopes3.symbols	2014-08-19 08:25:14 +0000
+++ debian/libunity-scopes3.symbols	2014-08-26 05:49:51 +0000
@@ -507,6 +507,7 @@
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::update_state(unity::scopes::internal::RegistryObject::ScopeProcess::ProcessState)@Base" 0.4.2+14.04.20140404.2
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::on_process_death(int)@Base" 0.4.2+14.04.20140404.2
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::expand_custom_exec()@Base" 0.5.0+14.10.20140619
+ (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::publish_state_change(unity::scopes::internal::RegistryObject::ScopeProcess::ProcessState)@Base" 0replaceme
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::clear_handle_unlocked()@Base" 0.4.2+14.04.20140404.2
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::update_state_unlocked(unity::scopes::internal::RegistryObject::ScopeProcess::ProcessState)@Base" 0.4.2+14.04.20140404.2
  (c++)"unity::scopes::internal::RegistryObject::ScopeProcess::exec(core::posix::ChildProcess::DeathObserver&, std::shared_ptr<unity::scopes::internal::Executor>)@Base" 0.4.3+14.10.20140428

=== modified file 'include/unity/scopes/internal/RegistryObject.h'
--- include/unity/scopes/internal/RegistryObject.h	2014-08-08 06:44:28 +0000
+++ include/unity/scopes/internal/RegistryObject.h	2014-08-26 05:49:51 +0000
@@ -53,6 +53,7 @@
         std::string scope_config;
         std::string confinement_profile;
         int timeout_ms;
+        bool debug_mode;
     };
 
 public:
@@ -111,6 +112,7 @@
         void kill(std::unique_lock<std::mutex>& lock);
 
         std::vector<std::string> expand_custom_exec();
+        void publish_state_change(ProcessState scope_state);
 
     private:
         const ScopeExecData exec_data_;

=== modified file 'include/unity/scopes/internal/Utils.h'
--- include/unity/scopes/internal/Utils.h	2014-06-25 16:29:26 +0000
+++ include/unity/scopes/internal/Utils.h	2014-08-26 05:49:51 +0000
@@ -54,6 +54,8 @@
 template<>
 bool convert_to<bool>(std::string const& val, Variant& out);
 
+int safe_system_call(std::string const& command);
+
 } // namespace internal
 
 } // namespace scopes

=== modified file 'scoperegistry/scoperegistry.cpp'
--- scoperegistry/scoperegistry.cpp	2014-08-17 01:47:41 +0000
+++ scoperegistry/scoperegistry.cpp	2014-08-26 05:49:51 +0000
@@ -428,6 +428,7 @@
     }
     exec_data.runtime_config = config_file;
     exec_data.scope_config = scope.second;
+    exec_data.debug_mode = sc.debug_mode();
 
     registry->add_local_scope(scope.first, move(meta), exec_data);
 }

=== modified file 'src/scopes/internal/RegistryObject.cpp'
--- src/scopes/internal/RegistryObject.cpp	2014-08-18 06:07:34 +0000
+++ src/scopes/internal/RegistryObject.cpp	2014-08-26 05:49:51 +0000
@@ -20,6 +20,7 @@
 
 #include <unity/scopes/internal/MWRegistry.h>
 #include <unity/scopes/internal/RuntimeImpl.h>
+#include <unity/scopes/internal/Utils.h>
 #include <unity/scopes/ScopeExceptions.h>
 #include <unity/UnityExceptions.h>
 #include <unity/util/ResourcePtr.h>
@@ -35,6 +36,9 @@
 
 using namespace std;
 
+static const char* c_debug_dbus_started_cmd = "dbus-send --type=method_call --dest=com.ubuntu.SDKAppLaunch /ScopeRegistryCallback com.ubuntu.SDKAppLaunch.ScopeLoaded";
+static const char* c_debug_dbus_stopped_cmd = "dbus-send --type=method_call --dest=com.ubuntu.SDKAppLaunch /ScopeRegistryCallback com.ubuntu.SDKAppLaunch.ScopeStopped";
+
 namespace unity
 {
 
@@ -524,11 +528,7 @@
     }
     else if (new_state == Running)
     {
-        if (reg_publisher_)
-        {
-            // Send a "started" message to subscribers to inform them that this scope (topic) has started
-            reg_publisher_->send_message("started", exec_data_.scope_id);
-        }
+        publish_state_change(Running);
 
         if (state_ != Starting)
         {
@@ -540,11 +540,7 @@
     }
     else if (new_state == Stopped)
     {
-        if (reg_publisher_)
-        {
-            // Send a "stopped" message to subscribers to inform them that this scope (topic) has stopped
-            reg_publisher_->send_message("stopped", exec_data_.scope_id);
-        }
+        publish_state_change(Stopped);
 
         if (state_ != Stopping)
         {
@@ -554,11 +550,7 @@
     }
     else if (new_state == Stopping && manually_started_)
     {
-        if (reg_publisher_)
-        {
-            // Send a "stopped" message to subscribers to inform them that this scope (topic) has stopped
-            reg_publisher_->send_message("stopped", exec_data_.scope_id);
-        }
+        publish_state_change(Stopped);
 
         cout << "RegistryObject::ScopeProcess: Manually started process for scope: \""
              << exec_data_.scope_id << "\" exited" << endl;
@@ -664,6 +656,50 @@
     return command_args;
 }
 
+void RegistryObject::ScopeProcess::publish_state_change(ProcessState scope_state)
+{
+    if (scope_state == Running)
+    {
+        if (reg_publisher_)
+        {
+            // Send a "started" message to subscribers to inform them that this scope (topic) has started
+            reg_publisher_->send_message("started", exec_data_.scope_id);
+        }
+        if (exec_data_.debug_mode)
+        {
+            // If we're in debug mode, callback to the SDK via dbus (used to monitor scope lifecycle)
+            std::string started_message = c_debug_dbus_started_cmd;
+            started_message += " string:" + exec_data_.scope_id + " uint64:" + std::to_string(process_.pid());
+            if (safe_system_call(started_message) != 0)
+            {
+                std::cerr << "RegistryObject::ScopeProcess::publish_state_change(): "
+                             "Failed to execute SDK DBus ScopeLoaded callback "
+                             "(Scope ID: " << exec_data_.scope_id << ")" << endl;
+            }
+        }
+    }
+    else if (scope_state == Stopped)
+    {
+        if (reg_publisher_)
+        {
+            // Send a "stopped" message to subscribers to inform them that this scope (topic) has stopped
+            reg_publisher_->send_message("stopped", exec_data_.scope_id);
+        }
+        if (exec_data_.debug_mode)
+        {
+            // If we're in debug mode, callback to the SDK via dbus (used to monitor scope lifecycle)
+            std::string stopped_message = c_debug_dbus_stopped_cmd;
+            stopped_message += " string:" + exec_data_.scope_id;
+            if (safe_system_call(stopped_message) != 0)
+            {
+                std::cerr << "RegistryObject::ScopeProcess::publish_state_change(): "
+                             "Failed to execute SDK DBus ScopeStopped callback "
+                             "(Scope ID: " << exec_data_.scope_id << ")" << endl;
+            }
+        }
+    }
+}
+
 } // namespace internal
 
 } // namespace scopes

=== modified file 'src/scopes/internal/Utils.cpp'
--- src/scopes/internal/Utils.cpp	2014-08-05 05:29:56 +0000
+++ src/scopes/internal/Utils.cpp	2014-08-26 05:49:51 +0000
@@ -21,6 +21,7 @@
 #include <unity/UnityExceptions.h>
 #include <iomanip>
 #include <locale>
+#include <mutex>
 
 namespace unity
 {
@@ -142,6 +143,13 @@
     return false;
 }
 
+int safe_system_call(std::string const& command)
+{
+    static std::mutex system_mutex;
+    std::lock_guard<std::mutex> lock(system_mutex);
+    return std::system(command.c_str());
+}
+
 } // namespace internal
 
 } // namespace scopes

=== modified file 'src/scopes/internal/smartscopes/SSRegistryObject.cpp'
--- src/scopes/internal/smartscopes/SSRegistryObject.cpp	2014-08-20 07:58:15 +0000
+++ src/scopes/internal/smartscopes/SSRegistryObject.cpp	2014-08-26 05:49:51 +0000
@@ -25,6 +25,7 @@
 #include <unity/scopes/internal/ScopeImpl.h>
 #include <unity/scopes/internal/ScopeMetadataImpl.h>
 #include <unity/scopes/internal/smartscopes/HttpClientQt.h>
+#include <unity/scopes/internal/Utils.h>
 #include <unity/scopes/ScopeExceptions.h>
 #include <unity/UnityExceptions.h>
 
@@ -374,7 +375,7 @@
     if (changed)
     {
         // something has changed, send invalidate signal
-        int result = system(c_dbussend_cmd);
+        int result = safe_system_call(c_dbussend_cmd);
         (void)result;
     }
 }