Bug 1322574 - 2. Measure Android event loop latency; r=snorp
authorJim Chen <nchen@mozilla.com>
Wed, 21 Dec 2016 13:37:20 -0500
changeset 326960 091ed19d02e00b1c45347f43e875eb37c5a46863
parent 326959 bd18d639e3e184bf261126f0421e4ef548d57a02
child 326961 bd4a0d0bc458174c58316983df64e49aae688337
push id31116
push userkwierso@gmail.com
push dateFri, 23 Dec 2016 02:37:16 +0000
treeherdermozilla-central@2785aaf276ba [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewerssnorp
bugs1322574
milestone53.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1322574 - 2. Measure Android event loop latency; r=snorp Measure the latency of each event in the Android event loop by tagging each event with the time that the event was posted, and then recording the time interval between posting and processing the event. Latencies for UI events and non-UI events are recorded separately in Telemetry.
widget/android/nsAppShell.cpp
widget/android/nsAppShell.h
--- a/widget/android/nsAppShell.cpp
+++ b/widget/android/nsAppShell.cpp
@@ -25,16 +25,18 @@
 #include "nsIPowerManagerService.h"
 #include "nsISpeculativeConnect.h"
 #include "nsIURIFixup.h"
 #include "nsCategoryManagerUtils.h"
 #include "nsCDefaultURIFixup.h"
 #include "nsToolkitCompsCID.h"
 #include "nsGeoPosition.h"
 
+#include "mozilla/ArrayUtils.h"
+#include "mozilla/Telemetry.h"
 #include "mozilla/Services.h"
 #include "mozilla/Preferences.h"
 #include "mozilla/Hal.h"
 #include "prenv.h"
 
 #include "AndroidBridge.h"
 #include "AndroidBridgeUtilities.h"
 #include "GeneratedJNINatives.h"
@@ -76,16 +78,19 @@
 
 using namespace mozilla;
 
 nsIGeolocationUpdate *gLocationCallback = nullptr;
 
 nsAppShell* nsAppShell::sAppShell;
 StaticAutoPtr<Mutex> nsAppShell::sAppShellLock;
 
+uint32_t nsAppShell::Queue::sLatencyCount[];
+uint64_t nsAppShell::Queue::sLatencyTime[];
+
 NS_IMPL_ISUPPORTS_INHERITED(nsAppShell, nsBaseAppShell, nsIObserver)
 
 class WakeLockListener final : public nsIDOMMozWakeLockListener {
 private:
   ~WakeLockListener() {}
 
 public:
   NS_DECL_ISUPPORTS;
@@ -425,16 +430,53 @@ nsAppShell::~nsAppShell()
 }
 
 void
 nsAppShell::NotifyNativeEvent()
 {
     mEventQueue.Signal();
 }
 
+void
+nsAppShell::RecordLatencies()
+{
+    if (!mozilla::Telemetry::CanRecordExtended()) {
+        return;
+    }
+
+    const mozilla::Telemetry::ID timeIDs[] = {
+        mozilla::Telemetry::ID::FENNEC_LOOP_UI_LATENCY,
+        mozilla::Telemetry::ID::FENNEC_LOOP_OTHER_LATENCY
+    };
+
+    static_assert(ArrayLength(Queue::sLatencyCount) == Queue::LATENCY_COUNT,
+                  "Count array length mismatch");
+    static_assert(ArrayLength(Queue::sLatencyTime) == Queue::LATENCY_COUNT,
+                  "Time array length mismatch");
+    static_assert(ArrayLength(timeIDs) == Queue::LATENCY_COUNT,
+                  "Time ID array length mismatch");
+
+    for (size_t i = 0; i < Queue::LATENCY_COUNT; i++) {
+        if (!Queue::sLatencyCount[i]) {
+            continue;
+        }
+
+        const uint64_t time = Queue::sLatencyTime[i] / 1000ull /
+                              Queue::sLatencyCount[i];
+        if (time) {
+            mozilla::Telemetry::Accumulate(
+                    timeIDs[i], uint32_t(std::min<uint64_t>(UINT32_MAX, time)));
+        }
+
+        // Reset latency counts.
+        Queue::sLatencyCount[i] = 0;
+        Queue::sLatencyTime[i] = 0;
+    }
+}
+
 #define PREFNAME_COALESCE_TOUCHES "dom.event.touch.coalescing.enabled"
 static const char* kObservedPrefs[] = {
   PREFNAME_COALESCE_TOUCHES,
   nullptr
 };
 
 nsresult
 nsAppShell::Init()
--- a/widget/android/nsAppShell.h
+++ b/widget/android/nsAppShell.h
@@ -1,16 +1,18 @@
 /* -*- Mode: c++; tab-width: 40; indent-tabs-mode: nil; c-basic-offset: 4; -*- */
 /* This Source Code Form is subject to the terms of the Mozilla Public
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
 #ifndef nsAppShell_h__
 #define nsAppShell_h__
 
+#include <time.h>
+
 #include "mozilla/HangMonitor.h"
 #include "mozilla/LinkedList.h"
 #include "mozilla/Monitor.h"
 #include "mozilla/Move.h"
 #include "mozilla/StaticPtr.h"
 #include "mozilla/UniquePtr.h"
 #include "mozilla/Unused.h"
 #include "mozilla/jni/Natives.h"
@@ -30,16 +32,27 @@ class nsWindow;
 class nsAppShell :
     public nsBaseAppShell
 {
 public:
     struct Event : mozilla::LinkedListElement<Event>
     {
         typedef mozilla::HangMonitor::ActivityType Type;
 
+        static uint64_t GetTime()
+        {
+            timespec time;
+            if (clock_gettime(CLOCK_MONOTONIC, &time)) {
+                return 0ull;
+            }
+            return uint64_t(time.tv_sec) * 1000000000ull + time.tv_nsec;
+        }
+
+        uint64_t mPostTime{ 0 };
+
         bool HasSameTypeAs(const Event* other) const
         {
             // Compare vtable addresses to determine same type.
             return *reinterpret_cast<const uintptr_t*>(this)
                     == *reinterpret_cast<const uintptr_t*>(other);
         }
 
         virtual ~Event() {}
@@ -143,16 +156,18 @@ public:
     nsIAndroidBrowserApp* GetBrowserApp() {
         return mBrowserApp;
     }
 
 protected:
     static nsAppShell* sAppShell;
     static mozilla::StaticAutoPtr<mozilla::Mutex> sAppShellLock;
 
+    static void RecordLatencies();
+
     virtual ~nsAppShell();
 
     nsresult AddObserver(const nsAString &aObserverKey, nsIObserver *aObserver);
 
     class NativeCallbackEvent : public Event
     {
         // Capturing the nsAppShell instance is safe because if the app
         // shell is detroyed, this lambda will not be called either.
@@ -170,47 +185,74 @@ protected:
 
     class Queue
     {
     private:
         mozilla::Monitor mMonitor;
         mozilla::LinkedList<Event> mQueue;
 
     public:
+        enum {
+            LATENCY_UI,
+            LATENCY_OTHER,
+            LATENCY_COUNT
+        };
+        static uint32_t sLatencyCount[LATENCY_COUNT];
+        static uint64_t sLatencyTime[LATENCY_COUNT];
+
         Queue() : mMonitor("nsAppShell.Queue")
         {}
 
         void Signal()
         {
             mozilla::MonitorAutoLock lock(mMonitor);
             lock.NotifyAll();
         }
 
         void Post(mozilla::UniquePtr<Event>&& event)
         {
             MOZ_ASSERT(event && !event->isInList());
 
             mozilla::MonitorAutoLock lock(mMonitor);
             event->PostTo(mQueue);
             if (event->isInList()) {
+                event->mPostTime = Event::GetTime();
                 // Ownership of event object transfers to the queue.
                 mozilla::Unused << event.release();
             }
             lock.NotifyAll();
         }
 
         mozilla::UniquePtr<Event> Pop(bool mayWait)
         {
             mozilla::MonitorAutoLock lock(mMonitor);
 
             if (mayWait && mQueue.isEmpty()) {
+#ifdef EARLY_BETA_OR_EARLIER
+                // Record latencies when we're about to be idle.
+                nsAppShell::RecordLatencies();
+#endif
                 lock.Wait();
             }
+
             // Ownership of event object transfers to the return value.
-            return mozilla::UniquePtr<Event>(mQueue.popFirst());
+            mozilla::UniquePtr<Event> event(mQueue.popFirst());
+            if (!event || !event->mPostTime) {
+                return Move(event);
+            }
+
+#ifdef EARLY_BETA_OR_EARLIER
+            const size_t latencyType = (event->ActivityType() ==
+                    Event::Type::kUIActivity) ? LATENCY_UI : LATENCY_OTHER;
+            const uint64_t latency = Event::GetTime() - event->mPostTime;
+
+            sLatencyCount[latencyType]++;
+            sLatencyTime[latencyType] += latency;
+#endif
+            return Move(event);
         }
 
     } mEventQueue;
 
     mozilla::CondVar mSyncRunFinished;
     bool mSyncRunQuit;
 
     bool mAllowCoalescingTouches;