Merge lp:~vanvugt/mir/fix-r1049-regressions into lp:mir

[Daniel van Vugt]

Fix significant performance issues LP: #1241369 / LP: #1241371, and probably
more(!)

Added regression test to catch such regressions and revert the offending
commit r1049.

The problem was the new algorithm in r1049, in keeping one buffer always allocated to compositing, did not have room in the queue to properly pipeline subsequent client buffer allocations. So clients got much less frame time than they often need and some of them dropped down to half frame rate.

[PS Jenkins bot (ps-jenkins)]

FAILED: Continuous integration, rev:1151
http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-ci/194/
Executed test runs:
    FAILURE: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2414/console
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2299
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/191
        deb: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/191/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/194/rebuild

review: Needs Fixing (continuous-integration)

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:1151
http://jenkins.qa.ubuntu.com/job/mir-ci/1595/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2415
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2300
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-saucy-amd64-ci/839
        deb: http://jenkins.qa.ubuntu.com/job/mir-saucy-amd64-ci/839/artifact/work/output/*zip*/output.zip
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/96
        deb: http://jenkins.qa.ubuntu.com/job/mir-saucy-armhf-ci/96/artifact/work/output/*zip*/output.zip

Click here to trigger a rebuild:
http://10.97.0.26:8080/job/mir-ci/1595/rebuild

review: Approve (continuous-integration)

[Kevin DuBois (kdub)]

seems the test would take at least 1s to run (because of the sleep in 236) could we make it run faster?

review: Needs Information

[Daniel van Vugt (vanvugt)]

The test loses accuracy if you shorten it. So for the sake of a second or so I'd rather keep it how it is.

[PS Jenkins bot (ps-jenkins)]

PASSED: Continuous integration, rev:1152
http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-ci/206/
Executed test runs:
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-android-saucy-i386-build/2433
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-clang-saucy-amd64-build/2318
    SUCCESS: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/203
        deb: http://jenkins.qa.ubuntu.com/job/mir-team-mir-development-branch-saucy-amd64-ci/203/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/206/rebuild

review: Approve (continuous-integration)

[Alexandros Frantzis (afrantzis)]

296 + sync.lock();
297 + sync.unlock();

?

review: Needs Information

[Daniel van Vugt (vanvugt)]

The weird-looking sync.lock/unlock() calls help to create exactly the right (wrong) timing conditions between the two threads necessary to reproduce the problem reliably (and so fails without the fix). Otherwise it's surprisingly difficult to reproduce.

[Alexandros Frantzis (afrantzis)]

OK. Hopefully we can find a way to restore the strong guarantee of the compositor always having a buffer without adversely affecting performance.

review: Approve

[Kevin DuBois (kdub)]

+1 on Alexandros's comment.

I'd still rather have a shorter-running test, but I'd rather have fewer bugs/more performance...
This algorithm has gotten away from deep comprehension on my part, but looks good to me.

review: Approve

[Kevin DuBois (kdub)]

> +1 on Alexandros's comment.
>
> I'd still rather have a shorter-running test, but I'd prefer fewer
> bugs/more performance more than I want a shorter running test...

> This algorithm has gotten away from deep comprehension on my part, but looks
> good to me.

[Daniel van Vugt (vanvugt)]

The test is designed to simulate the root cause (which is subtle and apparently not common enough for us to notice for quite a while).

The root cause is that in designating one buffer to compositor, even when it's not being used, that buffer is unavailable to become a client buffer even while the client has a "ready" buffer queued up (but the compositor hasn't yet ticked over and asked for the next compositor buffer). The result is that clients have to wait longer to acquire a buffer, and for slow-ish clients, this can mean missing the frame deadline. And it happens repeatedly, so you stay at half frame rate.

I started with a naive fix, to simply promote any ready buffer to "compositor" if there were no "used" compositor buffers at the time. As a fix that worked, but it also results in many clients continuously skipping a buffer and thus rendering at double frame rate: 120Hz.

With additional logic and complexity, it would be possible to reinstate the current algorithm. But I figure the pre-1049 algorithm is better tested and already known to provide correct sync.

=== modified file 'src/server/compositor/switching_bundle.cpp'
--- src/server/compositor/switching_bundle.cpp	2013-09-02 09:20:16 +0000
+++ src/server/compositor/switching_bundle.cpp	2013-10-21 08:54:23 +0000
@@ -28,7 +28,7 @@
  *
  * The successive stages are contiguous elements in the ring (starting at
  * element "first_compositor"):
- *    first_compositor * ncompositors(one or more)
+ *    first_compositor * ncompositors(zero or more)
  *    first_ready      * nready(zero or more)
  *    first_client     * nclients(zero or more)
  *
@@ -72,18 +72,18 @@
     : bundle_properties{property_request},
       gralloc{gralloc},
       nbuffers{nbuffers},
-      first_compositor{0}, ncompositors{1},
-      first_ready{first_compositor + ncompositors}, nready{0},
-      first_client{first_ready + nready}, nclients{0},
+      first_compositor{0}, ncompositors{0},
+      first_ready{0}, nready{0},
+      first_client{0}, nclients{0},
       snapshot{-1}, nsnapshotters{0},
       last_consumed{0},
       overlapping_compositors{false},
       framedropping{false}, force_drop{0}
 {
-    if (nbuffers < 2 || nbuffers > MAX_NBUFFERS)
+    if (nbuffers < 1 || nbuffers > MAX_NBUFFERS)
     {
         BOOST_THROW_EXCEPTION(std::logic_error("SwitchingBundle only supports "
-                                               "nbuffers between 2 and " +
+                                               "nbuffers between 1 and " +
                                                std::to_string(MAX_NBUFFERS)));
     }
 }
@@ -264,9 +264,29 @@
     std::unique_lock<std::mutex> lock(guard);
     int compositor;
 
-    if (!nready || frameno == last_consumed)
+    // Multi-monitor acquires close to each other get the same frame:
+    bool same_frame = (frameno == last_consumed);
+
+    int avail = nfree();
+    bool can_recycle = ncompositors || avail;
+
+    if (!nready || (same_frame && can_recycle))
     {
-        compositor = last_compositor();
+        if (ncompositors)
+        {
+            compositor = last_compositor();
+        }
+        else if (avail)
+        {
+            first_compositor = prev(first_compositor);
+            compositor = first_compositor;
+            ncompositors++;
+        }
+        else
+        {
+            BOOST_THROW_EXCEPTION(std::logic_error(
+                "compositor_acquire would block; probably too many clients."));
+        }
     }
     else
     {
@@ -275,12 +295,6 @@
         nready--;
         ncompositors++;
         last_consumed = frameno;
-
-        while (ncompositors > 1 && !ring[first_compositor].users)
-        {
-            first_compositor = next(first_compositor);
-            ncompositors--;
-        }
     }
 
     overlapping_compositors = (ncompositors > 1);
@@ -303,7 +317,7 @@
         }
     }
 
-    if (compositor < 0 || ring[compositor].users <= 0)
+    if (compositor < 0)
     {
         BOOST_THROW_EXCEPTION(std::logic_error(
             "compositor_release given a non-compositor buffer"));
@@ -312,7 +326,7 @@
     ring[compositor].users--;
     if (compositor == first_compositor)
     {
-        while (ncompositors > 1 && !ring[first_compositor].users)
+        while (!ring[first_compositor].users && ncompositors)
         {
             first_compositor = next(first_compositor);
             ncompositors--;

=== modified file 'tests/mir_test_framework/testing_server_options.cpp'
--- tests/mir_test_framework/testing_server_options.cpp	2013-10-15 08:53:10 +0000
+++ tests/mir_test_framework/testing_server_options.cpp	2013-10-21 08:54:23 +0000
@@ -211,12 +211,10 @@
                         mc::CompositingCriteria const&, ms::BufferStream& stream)
     {
         // Need to acquire the texture to cycle buffers
-        stream.lock_compositor_buffer(++frameno);
+        stream.lock_compositor_buffer(0);
     }
 
     void clear(unsigned long) override {}
-
-    unsigned long frameno = 0;
 };
 
 class StubRendererFactory : public mc::RendererFactory

=== modified file 'tests/unit-tests/compositor/test_switching_bundle.cpp'
--- tests/unit-tests/compositor/test_switching_bundle.cpp	2013-09-17 13:21:10 +0000
+++ tests/unit-tests/compositor/test_switching_bundle.cpp	2013-10-21 08:54:23 +0000
@@ -24,6 +24,7 @@
 
 #include <atomic>
 #include <thread>
+#include <mutex>
 #include <chrono>
 
 namespace geom=mir::geometry;
@@ -57,7 +58,7 @@
                                     geom::PixelFormat::argb_8888,
                                     mg::BufferUsage::software};
 
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, properties);
 
@@ -91,7 +92,7 @@
 
 TEST_F(SwitchingBundleTest, client_acquire_basic)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
 
@@ -115,7 +116,7 @@
 
 TEST_F(SwitchingBundleTest, is_really_synchronous)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         mg::BufferID prev_id, prev_prev_id;
@@ -204,7 +205,7 @@
 
 TEST_F(SwitchingBundleTest, out_of_order_client_release)
 {
-    for (int nbuffers = 3; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
 
@@ -225,7 +226,7 @@
 
 TEST_F(SwitchingBundleTest, compositor_acquire_basic)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         unsigned long frameno = 0;
@@ -246,7 +247,7 @@
 
 TEST_F(SwitchingBundleTest, compositor_acquire_never_blocks)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         unsigned long frameno = 0;
@@ -265,7 +266,7 @@
 
 TEST_F(SwitchingBundleTest, compositor_acquire_recycles_latest_ready_buffer)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         unsigned long frameno = 1;
@@ -354,7 +355,7 @@
 
 TEST_F(SwitchingBundleTest, snapshot_acquire_basic)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
 
@@ -368,7 +369,7 @@
 
 TEST_F(SwitchingBundleTest, snapshot_acquire_never_blocks)
 {
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         const int N = 100;
@@ -511,7 +512,7 @@
      * unique ones while it makes sense to do so. Buffers are big things and
      * should be allocated sparingly...
      */
-    for (int nbuffers = 2; nbuffers <= 5; nbuffers++)
+    for (int nbuffers = 1; nbuffers <= 5; nbuffers++)
     {
         mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
         unsigned long frameno = 0;
@@ -581,7 +582,7 @@
     }
 }
 
-TEST_F(SwitchingBundleTest, framedropping_clients_get_all_but_one_buffers)
+TEST_F(SwitchingBundleTest, framedropping_clients_get_all_buffers)
 {
     const int max_nbuffers = 5;
     for (int nbuffers = 2; nbuffers <= max_nbuffers; nbuffers++)
@@ -594,7 +595,7 @@
         mg::BufferID expect[max_nbuffers];
         std::shared_ptr<mg::Buffer> buf[max_nbuffers];
 
-        for (int b = 0; b < nbuffers - 1; b++)
+        for (int b = 0; b < nbuffers; b++)
         {
             buf[b] = bundle.client_acquire();
             expect[b] = buf[b]->id();
@@ -603,13 +604,13 @@
                 ASSERT_NE(expect[p], expect[b]);
         }
 
-        for (int b = 0; b < nbuffers - 1; b++)
+        for (int b = 0; b < nbuffers; b++)
             bundle.client_release(buf[b]);
 
         for (int frame = 0; frame < nframes; frame++)
         {
             auto client = bundle.client_acquire();
-            ASSERT_EQ(expect[frame % (nbuffers - 1)], client->id());
+            ASSERT_EQ(expect[frame % nbuffers], client->id());
             bundle.client_release(client);
         }
     }
@@ -699,3 +700,57 @@
     }
 }
 
+TEST_F(SwitchingBundleTest, slow_client_framerate_matches_compositor)
+{  // Regression test LP: #1241369 / LP: #1241371
+    for (int nbuffers = 2; nbuffers <= 3; nbuffers++)
+    {
+        mc::SwitchingBundle bundle(nbuffers, allocator, basic_properties);
+        unsigned long client_frames = 0;
+        const unsigned long compose_frames = 100;
+        const auto frame_time = std::chrono::milliseconds(16);
+
+        bundle.allow_framedropping(false);
+
+        std::atomic<bool> done(false);
+        std::mutex sync;
+
+        std::thread monitor1([&]
+        {
+            for (unsigned long frame = 0; frame != compose_frames+3; frame++)
+            {
+                std::this_thread::sleep_for(frame_time);
+                sync.lock();
+                auto buf = bundle.compositor_acquire(frame);
+                bundle.compositor_release(buf);
+                sync.unlock();
+
+                if (frame == compose_frames)
+                {
+                    // Tell the "client" to stop after compose_frames, but
+                    // don't stop rendering immediately to avoid blocking
+                    // if we rendered any twice
+                    done.store(true);
+                }
+            }
+        });
+
+        bundle.client_release(bundle.client_acquire());
+
+        while (!done.load())
+        {
+            sync.lock();
+            sync.unlock();
+            auto buf = bundle.client_acquire();
+            std::this_thread::sleep_for(frame_time);
+            bundle.client_release(buf);
+            client_frames++;
+        }
+
+        monitor1.join();
+
+        // Roughly compose_frames == client_frames within 20%
+        ASSERT_GT(client_frames, compose_frames * 0.8f);
+        ASSERT_LT(client_frames, compose_frames * 1.2f);
+    }
+}
+