Merge lp:~alan-griffiths/mir/fix-client-hang-on-server-death into lp:mir

[Alan Griffiths]

client: fix hang(s) in client API when server dies

client: fix hang(s) in client API when server dies

Depending upon what calls are in progress when the server dies the client API could fail to return/callback

[Alan Griffiths (alan-griffiths)]

There's a strange interaction between TestClientInput.* and the tests that follow (ServerShutdown/OnSignal.*).

With the original timeout and running under valgrind I sometimes see the latter fail after valgrind reports errors in the former.

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:1133
http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-ci/159/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2343
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2228
    FAILURE: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/156/console

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/mir-team-mir-development-branch-ci/159/rebuild

review: Needs Fixing (continuous-integration)

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:1134
http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-ci/160/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2346
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2231
    FAILURE: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/157/console

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/mir-team-mir-development-branch-ci/160/rebuild

review: Needs Fixing (continuous-integration)

[Kevin DuBois (kdub)]

lgtm, or at least can't see anything wrong. :)

review: Approve

[Daniel van Vugt (vanvugt)]

1. Slightly confused but it's probably nothing:
Bug 1227743 says it's the server that hangs, while this MP seems to say it fixes client hangs. Is it both?

2. Your description seems to suggest this might fix bug 1237710 too. Will have to test...

[Daniel van Vugt (vanvugt)]

review: Needs Information

[Daniel van Vugt (vanvugt)]

Correction:

2. Your comment seems to suggest bug 1227683 and/or bug 1237710 might benefit from this. Will have to test...

[Daniel van Vugt (vanvugt)]

Sorry, I got excited. Neither bug 1237710 or 1227683 are solved here.

Still needs information;
Bug 1227743 says it's the server that hangs, while this MP seems to say it fixes client hangs. Is it both?

review: Needs Information

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:1135
http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-ci/170/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2369
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2254
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/167
        deb: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/167/artifact/work/output/*zip*/output.zip

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/mir-team-mir-development-branch-ci/170/rebuild

review: Approve (continuous-integration)

[Alan Griffiths (alan-griffiths)]

I didn't find time to get to the bottom of the test failures

review: Needs Fixing

[Daniel van Vugt (vanvugt)]

Alan,

No need to block on that test failure. You didn't cause it. See bug 1227683.

[Alan Griffiths (alan-griffiths)]

> Alan,
>
> No need to block on that test failure. You didn't cause it. See bug 1227683.

I think it is bug 1237710

review: Abstain

[Alan Griffiths (alan-griffiths)]

> Still needs information;
> Bug 1227743 says it's the server that hangs, while this MP seems to say it
> fixes client hangs. Is it both?

The server hangs because the clients are holding some (unidentified) resource. The clients are stalled by the Mir API - this fix allows the clients to release resources (and optionally exit).

=== modified file 'src/client/logging/rpc_report.cpp'
--- src/client/logging/rpc_report.cpp	2013-09-26 13:50:11 +0000
+++ src/client/logging/rpc_report.cpp	2013-10-15 10:44:56 +0000
@@ -104,7 +104,7 @@
     /* TODO: Log more information about event */
     ss << "Event parsed";
 
-    logger->log<ml::Logger::error>(ss.str(), component);
+    logger->log<ml::Logger::debug>(ss.str(), component);
 }
 
 void mcll::RpcReport::event_parsing_failed(

=== modified file 'src/client/rpc/mir_socket_rpc_channel.cpp'
--- src/client/rpc/mir_socket_rpc_channel.cpp	2013-10-14 06:33:42 +0000
+++ src/client/rpc/mir_socket_rpc_channel.cpp	2013-10-15 10:44:56 +0000
@@ -39,6 +39,12 @@
 namespace mcl = mir::client;
 namespace mclr = mir::client::rpc;
 
+namespace
+{
+std::chrono::milliseconds const timeout(200);
+boost::posix_time::milliseconds const boost_timeout(2000);
+}
+
 mclr::MirSocketRpcChannel::MirSocketRpcChannel(
     std::string const& endpoint,
     std::shared_ptr<mcl::SurfaceMap> const& surface_map,
@@ -49,6 +55,7 @@
     pending_calls(rpc_report),
     work(io_service),
     socket(io_service),
+    timer(io_service),
     surface_map(surface_map),
     display_configuration(disp_config),
     lifecycle_control(lifecycle_control),
@@ -68,6 +75,7 @@
     pending_calls(rpc_report),
     work(io_service),
     socket(io_service),
+    timer(io_service),
     surface_map(surface_map),
     display_configuration(disp_config),
     lifecycle_control(lifecycle_control),
@@ -82,6 +90,7 @@
     if (!disconnected.exchange(true))
     {
         io_service.stop();
+        socket.close();
         lifecycle_control->call_lifecycle_event_handler(mir_lifecycle_connection_lost);
         pending_calls.force_completion();
     }
@@ -89,7 +98,7 @@
 
 void mclr::MirSocketRpcChannel::init()
 {
-    io_service_thread = std::thread([&]
+    io_service_thread = std::thread([this]
         {
             // Our IO threads must not receive any signals
             sigset_t all_signals;
@@ -122,6 +131,7 @@
 
 mclr::MirSocketRpcChannel::~MirSocketRpcChannel()
 {
+    timer.cancel();
     io_service.stop();
 
     if (io_service_thread.joinable())
@@ -134,67 +144,69 @@
 void mclr::MirSocketRpcChannel::receive_file_descriptors(google::protobuf::Message* response,
     google::protobuf::Closure* complete)
 {
-    auto surface = dynamic_cast<mir::protobuf::Surface*>(response);
-    if (surface)
-    {
-        surface->clear_fd();
-
-        if (surface->fds_on_side_channel() > 0)
-        {
-            std::vector<int32_t> fds(surface->fds_on_side_channel());
-            receive_file_descriptors(fds);
-            for (auto &fd: fds)
-                surface->add_fd(fd);
-
-            rpc_report->file_descriptors_received(*response, fds);
-        }
-    }
-
-    auto buffer = dynamic_cast<mir::protobuf::Buffer*>(response);
-    if (!buffer)
-    {
-        if (surface && surface->has_buffer())
-            buffer = surface->mutable_buffer();
-    }
-
-    if (buffer)
-    {
-        buffer->clear_fd();
-
-        if (buffer->fds_on_side_channel() > 0)
-        {
-            std::vector<int32_t> fds(buffer->fds_on_side_channel());
-            receive_file_descriptors(fds);
-            for (auto &fd: fds)
-                buffer->add_fd(fd);
-
-            rpc_report->file_descriptors_received(*response, fds);
-        }
-    }
-
-    auto platform = dynamic_cast<mir::protobuf::Platform*>(response);
-    if (!platform)
-    {
-        auto connection = dynamic_cast<mir::protobuf::Connection*>(response);
-        if (connection && connection->has_platform())
-            platform = connection->mutable_platform();
-    }
-
-    if (platform)
-    {
-        platform->clear_fd();
-
-        if (platform->fds_on_side_channel() > 0)
-        {
-            std::vector<int32_t> fds(platform->fds_on_side_channel());
-            receive_file_descriptors(fds);
-            for (auto &fd: fds)
-                platform->add_fd(fd);
-
-            rpc_report->file_descriptors_received(*response, fds);
-        }
-    }
-
+    if (!disconnected.load())
+    {
+        auto surface = dynamic_cast<mir::protobuf::Surface*>(response);
+        if (surface)
+        {
+            surface->clear_fd();
+
+            if (surface->fds_on_side_channel() > 0)
+            {
+                std::vector<int32_t> fds(surface->fds_on_side_channel());
+                receive_file_descriptors(fds);
+                for (auto &fd: fds)
+                    surface->add_fd(fd);
+
+                rpc_report->file_descriptors_received(*response, fds);
+            }
+        }
+
+        auto buffer = dynamic_cast<mir::protobuf::Buffer*>(response);
+        if (!buffer)
+        {
+            if (surface && surface->has_buffer())
+                buffer = surface->mutable_buffer();
+        }
+
+        if (buffer)
+        {
+            buffer->clear_fd();
+
+            if (buffer->fds_on_side_channel() > 0)
+            {
+                std::vector<int32_t> fds(buffer->fds_on_side_channel());
+                receive_file_descriptors(fds);
+                for (auto &fd: fds)
+                    buffer->add_fd(fd);
+
+                rpc_report->file_descriptors_received(*response, fds);
+            }
+        }
+
+        auto platform = dynamic_cast<mir::protobuf::Platform*>(response);
+        if (!platform)
+        {
+            auto connection = dynamic_cast<mir::protobuf::Connection*>(response);
+            if (connection && connection->has_platform())
+                platform = connection->mutable_platform();
+        }
+
+        if (platform)
+        {
+            platform->clear_fd();
+
+            if (platform->fds_on_side_channel() > 0)
+            {
+                std::vector<int32_t> fds(platform->fds_on_side_channel());
+                receive_file_descriptors(fds);
+                for (auto &fd: fds)
+                    platform->add_fd(fd);
+
+                rpc_report->file_descriptors_received(*response, fds);
+            }
+        }
+    }
 
     complete->Run();
 }
@@ -227,8 +239,14 @@
     message->cmsg_level = SOL_SOCKET;
     message->cmsg_type = SCM_RIGHTS;
 
+    using std::chrono::steady_clock;
+    auto time_limit = steady_clock::now() + timeout;
+
     while (recvmsg(socket.native_handle(), &header, 0) < 0)
-        ; // FIXME: Avoid spinning forever
+    {
+        if (steady_clock::now() > time_limit)
+            return;
+    }
 
     // Copy file descriptors back to caller
     n_fds = (message->cmsg_len - sizeof(struct cmsghdr)) / sizeof(int);
@@ -288,12 +306,19 @@
         notify_disconnected();
         BOOST_THROW_EXCEPTION(std::runtime_error("Failed to send message to server: " + error.message()));
     }
-    else
-        rpc_report->invocation_succeeded(invocation);
+
+    rpc_report->invocation_succeeded(invocation);
+    timer.expires_from_now(boost_timeout);
+    timer.async_wait([this](const boost::system::error_code& error)
+    {
+        // Timed out waiting for server response: kill the connection
+        if (!error) socket.cancel();
+    });
 }
 
 void mclr::MirSocketRpcChannel::on_header_read(const boost::system::error_code& error)
 {
+    timer.cancel();
     if (error)
     {
         // If we've not got a response to a call pending

=== modified file 'src/client/rpc/mir_socket_rpc_channel.h'
--- src/client/rpc/mir_socket_rpc_channel.h	2013-10-07 09:27:32 +0000
+++ src/client/rpc/mir_socket_rpc_channel.h	2013-10-15 10:44:56 +0000
@@ -77,6 +77,7 @@
     boost::asio::io_service io_service;
     boost::asio::io_service::work work;
     boost::asio::local::stream_protocol::socket socket;
+    boost::asio::deadline_timer timer;
 
     static size_t const size_of_header = 2;
     unsigned char header_bytes[size_of_header];