improve frame timing info

- we use a circular buffer for the frame history so that 
  we don't have to copy the data when insert a new entry.
  This also allows us to keep a reference to an entry, which
  doesn't get invalidated when an entry is added/removed.

- we now store the gpu frame time in the correct slot (instead of
  always the latest). It didn't matter before because the API wasn't
  public and we only needed some recent frame time.

- a new public API now returns the frame history, which now contains 
  more data; in particular the main and backend thread's begin/end
  frame time.


BUGS=[321110544]

filament/include/filament/Renderer.h

@@ -22,9 +22,11 @@
 #include <filament/FilamentAPI.h>
 
 #include <utils/compiler.h>
+#include <utils/FixedCapacityVector.h>
 
 #include <math/vec4.h>
 
+#include <stddef.h>
 #include <stdint.h>
 
 namespace filament {
@@ -81,6 +83,37 @@ public:
         UTILS_DEPRECATED uint64_t vsyncOffsetNanos = 0;
     };
 
+    /**
+     * Timing information about a frame
+     * @see getFrameInfoHistory()
+     */
+    struct FrameInfo {
+        using time_point_ns = int64_t;
+        using duration_ns = int64_t;
+        uint32_t frameId;                   //!< monotonically increasing frame identifier
+        duration_ns frameTime;              //!< frame duration on the GPU in nanosecond [ns]
+        duration_ns denoisedFrameTime;      //!< denoised frame duration on the GPU in [ns]
+        time_point_ns beginFrame;           //!< Renderer::beginFrame() time since epoch [ns]
+        time_point_ns endFrame;             //!< Renderer::endFrame() time since epoch [ns]
+        time_point_ns backendBeginFrame;    //!< Backend thread time of frame start since epoch [ns]
+        time_point_ns backendEndFrame;      //!< Backend thread time of frame end since epoch [ns]
+    };
+
+    /**
+     * Retrieve an historic of frame timing information. The maximum frame history size is
+     * given by getMaxFrameHistorySize().
+     * @param historySize requested history size. The returned vector could be smaller.
+     * @return A vector of FrameInfo.
+     */
+    utils::FixedCapacityVector<Renderer::FrameInfo> getFrameInfoHistory(
+            size_t historySize = 1) const noexcept;
+
+    /**
+     * @return the maximum supported frame history size.
+     * @see getFrameInfoHistory()
+     */
+    size_t getMaxFrameHistorySize() const noexcept;
+
     /**
      * Use FrameRateOptions to set the desired frame rate and control how quickly the system
      * reacts to GPU load changes.

filament/src/FrameInfo.cpp

@@ -16,30 +16,33 @@
 
 #include "FrameInfo.h"
 
+#include <filament/Renderer.h>
+
+#include <backend/DriverEnums.h>
+
+#include <utils/compiler.h>
+#include <utils/debug.h>
+#include <utils/FixedCapacityVector.h>
 #include <utils/Log.h>
-#include <utils/Systrace.h>
+#include <utils/ostream.h>
 
-#include <math/scalar.h>
+#include <algorithm>
+#include <atomic>
+#include <chrono>
+#include <memory>
+#include <ratio>
 
-#include <cmath>
+#include <stdint.h>
+#include <stddef.h>
 
 namespace filament {
 
 using namespace utils;
 using namespace backend;
 
-// this is to avoid a call to memmove
-template<class InputIterator, class OutputIterator>
-static inline
-void move_backward(InputIterator first, InputIterator last, OutputIterator result) {
-    while (first != last) {
-        *--result = *--last;
-    }
-}
-
 FrameInfoManager::FrameInfoManager(DriverApi& driver) noexcept {
     for (auto& query : mQueries) {
-        query = driver.createTimerQuery();
+        query.handle = driver.createTimerQuery();
     }
 }
 
@@ -47,14 +50,36 @@ FrameInfoManager::~FrameInfoManager() noexcept = default;
 
 void FrameInfoManager::terminate(DriverApi& driver) noexcept {
     for (auto& query : mQueries) {
-        driver.destroyTimerQuery(query);
+        driver.destroyTimerQuery(query.handle);
     }
 }
 
-void FrameInfoManager::beginFrame(DriverApi& driver,Config const& config, uint32_t) noexcept {
-    driver.beginTimerQuery(mQueries[mIndex]);
+void FrameInfoManager::beginFrame(DriverApi& driver, Config const& config, uint32_t frameId) noexcept {
+    auto& history = mFrameTimeHistory;
+    // don't exceed the capacity, drop the oldest entry
+    if (UTILS_LIKELY(history.size() == history.capacity())) {
+        history.pop_back();
+    }
+
+    // create a new entry
+    auto& front = history.emplace_front(frameId);
+
+    // store the current time
+    front.beginFrame = std::chrono::steady_clock::now();
+
+    // references are not invalidated by CircularQueue<>, so we can associate a reference to
+    // the slot we created to the timer query used to find the frame time.
+    mQueries[mIndex].pInfo = std::addressof(front);
+    // issue the timer query
+    driver.beginTimerQuery(mQueries[mIndex].handle);
+    // issue the custom backend command to get the backend time
+    driver.queueCommand([&front](){
+        front.backendBeginFrame = std::chrono::steady_clock::now();
+    });
+
+    // now is a good time to check the oldest active query
     uint64_t elapsed = 0;
-    TimerQueryResult const result = driver.getTimerQueryValue(mQueries[mLast], &elapsed);
+    TimerQueryResult const result = driver.getTimerQueryValue(mQueries[mLast].handle, &elapsed);
     switch (result) {
         case TimerQueryResult::NOT_READY:
             // nothing to do
@@ -63,49 +88,111 @@ void FrameInfoManager::beginFrame(DriverApi& driver,Config const& config, uint32
             mLast = (mLast + 1) % POOL_COUNT;
             break;
         case TimerQueryResult::AVAILABLE:
-            mLast = (mLast + 1) % POOL_COUNT;
             // conversion to our duration happens here
-            mFrameTime = std::chrono::duration<uint64_t, std::nano>(elapsed);
+            pFront = mQueries[mLast].pInfo;
+            pFront->frameTime = std::chrono::duration<uint64_t, std::nano>(elapsed);
+            mLast = (mLast + 1) % POOL_COUNT;
+            denoiseFrameTime(config);
             break;
     }
-    update(config, mFrameTime);
+
+
+    // keep this just for debugging
+    if constexpr (false) {
+        using namespace utils;
+        auto h = getFrameInfoHistory(1);
+        if (!h.empty()) {
+            slog.d << frameId << ": "
+                   << h[0].frameId << " (" << frameId - h[0].frameId << ")"
+                   << ", Dm=" << h[0].endFrame - h[0].beginFrame
+                   << ", L =" << h[0].backendBeginFrame - h[0].beginFrame
+                   << ", Db=" << h[0].backendEndFrame - h[0].backendBeginFrame
+                   << ", T =" << h[0].frameTime
+                   << io::endl;
+        }
+    }
 }
 
 void FrameInfoManager::endFrame(DriverApi& driver) noexcept {
-    driver.endTimerQuery(mQueries[mIndex]);
+    auto& front = mFrameTimeHistory.front();
+    // close the timer query
+    driver.endTimerQuery(mQueries[mIndex].handle);
+    // queue custom backend command to query the current time
+    driver.queueCommand([&front](){
+        // backend frame end-time
+        front.backendEndFrame = std::chrono::steady_clock::now();
+        // signal that the data is available
+        front.ready.store(true, std::memory_order_release);
+    });
+    // and finally acquire the time on the main thread
+    front.endFrame = std::chrono::steady_clock::now();
     mIndex = (mIndex + 1) % POOL_COUNT;
 }
 
-void FrameInfoManager::update(Config const& config,
-        FrameInfoManager::duration lastFrameTime) noexcept {
-    // keep an history of frame times
+void FrameInfoManager::denoiseFrameTime(Config const& config) noexcept {
     auto& history = mFrameTimeHistory;
+    assert_invariant(!history.empty());
 
-    // this is like doing { pop_back(); push_front(); }
-    filament::move_backward(history.begin(), history.end() - 1, history.end());
-    history[0].frameTime = lastFrameTime;
-
-    mFrameTimeHistorySize = std::min(++mFrameTimeHistorySize, uint32_t(MAX_FRAMETIME_HISTORY));
-    if (UTILS_UNLIKELY(mFrameTimeHistorySize < 3)) {
-        // not enough history to do anything useful
-        history[0].valid = false;
-        return;
+    // find the first slot that has a valid frame duration
+    size_t first = history.size();
+    for (size_t i = 0, c = history.size(); i < c; ++i) {
+        if (history[i].frameTime != duration(0)) {
+            assert_invariant(std::addressof(history[i]) == pFront);
+            first = i;
+            break;
+        }
     }
+    assert_invariant(first != history.size());
 
-    // apply a median filter to get a good representation of the frame time of the last
-    // N frames.
-    std::array<duration, MAX_FRAMETIME_HISTORY> median; // NOLINT -- it's initialized below
-    size_t const size = std::min(mFrameTimeHistorySize,
-            std::min(config.historySize, (uint32_t)median.size()));
-    for (size_t i = 0; i < size; ++i) {
-        median[i] = history[i].frameTime;
-    }
-    std::sort(median.begin(), median.begin() + size);
-    duration const denoisedFrameTime = median[size / 2];
+    // we need at least 3 valid frame time to calculate the median
+    if (history.size() >= first + 3) {
+        // apply a median filter to get a good representation of the frame time of the last
+        // N frames.
+        std::array<duration, MAX_FRAMETIME_HISTORY> median; // NOLINT -- it's initialized below
+        size_t const size = std::min({
+            history.size() - first,
+            median.size(),
+            size_t(config.historySize) });
 
-    history[0].denoisedFrameTime = denoisedFrameTime;
-    history[0].valid = true;
+        for (size_t i = 0; i < size; ++i) {
+            median[i] = history[first + i].frameTime;
+        }
+        std::sort(median.begin(), median.begin() + size);
+        duration const denoisedFrameTime = median[size / 2];
+
+        history[first].denoisedFrameTime = denoisedFrameTime;
+        history[first].valid = true;
+     }
 }
 
+utils::FixedCapacityVector<Renderer::FrameInfo> FrameInfoManager::getFrameInfoHistory(
+        size_t historySize) const noexcept {
+    auto result = utils::FixedCapacityVector<Renderer::FrameInfo>::with_capacity(MAX_FRAMETIME_HISTORY);
+    auto const& history = mFrameTimeHistory;
+    size_t i = 0;
+    size_t const c = history.size();
+    for (; i < c; ++i) {
+        auto const& entry = history[i];
+        if (entry.ready.load(std::memory_order_acquire) && entry.valid) {
+            // once we found an entry ready,
+            // we know by construction that all following ones are too
+            break;
+        }
+    }
+    for (; i < c && historySize; ++i, --historySize) {
+        auto const& entry = history[i];
+        using namespace std::chrono;
+        result.push_back({
+                entry.frameId,
+                duration_cast<nanoseconds>(entry.frameTime).count(),
+                duration_cast<nanoseconds>(entry.denoisedFrameTime).count(),
+                duration_cast<nanoseconds>(entry.beginFrame.time_since_epoch()).count(),
+                duration_cast<nanoseconds>(entry.endFrame.time_since_epoch()).count(),
+                duration_cast<nanoseconds>(entry.backendBeginFrame.time_since_epoch()).count(),
+                duration_cast<nanoseconds>(entry.backendEndFrame.time_since_epoch()).count()
+        });
+    }
+    return result;
+}
 
 } // namespace filament

filament/src/FrameInfo.h

@@ -17,30 +17,136 @@
 #ifndef TNT_FILAMENT_FRAMEINFO_H
 #define TNT_FILAMENT_FRAMEINFO_H
 
-#include "backend/Handle.h"
+#include <filament/Renderer.h>
+
+#include <backend/Handle.h>
+
 #include <private/backend/DriverApi.h>
 
+#include <utils/compiler.h>
+#include <utils/debug.h>
+#include <utils/FixedCapacityVector.h>
+
 #include <array>
+#include <atomic>
 #include <chrono>
+#include <ratio>
+#include <type_traits>
 
 #include <stdint.h>
+#include <stddef.h>
 
 namespace filament {
 class FEngine;
 
+namespace details {
 struct FrameInfo {
     using duration = std::chrono::duration<float, std::milli>;
     duration frameTime{};            // frame period
     duration denoisedFrameTime{};    // frame period (median filter)
-    bool valid = false;
+    bool valid = false;              // true if the data of the structure is valid
+};
+} // namespace details
+
+struct FrameInfoImpl : public details::FrameInfo {
+    using clock = std::chrono::steady_clock;
+    using time_point = clock::time_point;
+    uint32_t const frameId;
+    time_point beginFrame;           // main thread beginFrame time
+    time_point endFrame;             // main thread endFrame time
+    time_point backendBeginFrame;    // backend thread beginFrame time (makeCurrent time)
+    time_point backendEndFrame;      // backend thread endFrame time (present time)
+    std::atomic_bool ready{};        // true once backend thread has populated its data
+    explicit FrameInfoImpl(uint32_t frameId) noexcept
+        : frameId(frameId) {
+    }
+};
+
+template<typename T, size_t CAPACITY>
+class CircularQueue {
+public:
+    using value_type = T;
+    using reference = value_type&;
+    using const_reference = value_type const&;
+
+    size_t capacity() const {
+        return CAPACITY;
+    }
+
+    size_t size() const {
+        return mSize;
+    }
+
+    bool empty() const noexcept {
+        return !size();
+    }
+
+    void pop_back() noexcept {
+        assert_invariant(!empty());
+        --mSize;
+        std::destroy_at(&mStorage[(mFront - mSize) % CAPACITY]);
+    }
+
+    void push_front(T const& v) noexcept {
+        assert_invariant(size() < CAPACITY);
+        mFront = advance(mFront);
+        new(&mStorage[mFront]) T(v);
+        ++mSize;
+    }
+
+    void push_front(T&& v) noexcept {
+        assert_invariant(size() < CAPACITY);
+        mFront = advance(mFront);
+        new(&mStorage[mFront]) T(std::move(v));
+        ++mSize;
+    }
+
+    template<typename ...Args>
+    T& emplace_front(Args&&... args) noexcept {
+        assert_invariant(size() < CAPACITY);
+        mFront = advance(mFront);
+        new(&mStorage[mFront]) T(std::forward<Args>(args)...);
+        ++mSize;
+        return front();
+    }
+
+    T& operator[](size_t pos) noexcept {
+        assert_invariant(pos < size());
+        size_t const index = (mFront + CAPACITY - pos) % CAPACITY;
+        return *std::launder(reinterpret_cast<T*>(&mStorage[index]));
+    }
+
+    T const& operator[](size_t pos) const noexcept {
+        return const_cast<CircularQueue&>(*this)[pos];
+    }
+
+    T const& front() const noexcept {
+        assert_invariant(!empty());
+        return operator[](0);
+    }
+
+    T& front() noexcept {
+        assert_invariant(!empty());
+        return operator[](0);
+    }
+
+private:
+    using Storage = std::aligned_storage_t<sizeof(T), alignof(T)>;
+    Storage mStorage[CAPACITY];
+    uint32_t mFront = 0;    // always index 0
+    uint32_t mSize = 0;
+    [[nodiscard]] inline uint32_t advance(uint32_t v) noexcept {
+        return (v + 1) % CAPACITY;
+    }
 };
 
 class FrameInfoManager {
     static constexpr size_t POOL_COUNT = 4;
-    static constexpr size_t MAX_FRAMETIME_HISTORY = 31u;
+    static constexpr size_t MAX_FRAMETIME_HISTORY = 16u;
 
 public:
-    using duration = FrameInfo::duration;
+    using duration = FrameInfoImpl::duration;
+    using clock = FrameInfoImpl::clock;
 
     struct Config {
         uint32_t historySize;
@@ -57,23 +163,24 @@ public:
     // call this immediately before "swap buffers"
     void endFrame(backend::DriverApi& driver) noexcept;
 
-    FrameInfo const& getLastFrameInfo() const noexcept {
-        return mFrameTimeHistory[0];
+    details::FrameInfo const& getLastFrameInfo() const noexcept {
+        // if pFront is not set yet, return front() but in this case front().valid will be false
+        return pFront ? *pFront : mFrameTimeHistory.front();
     }
 
-    duration getLastFrameTime() const noexcept {
-        return getLastFrameInfo().frameTime;
-    }
+    utils::FixedCapacityVector<Renderer::FrameInfo> getFrameInfoHistory(size_t historySize) const noexcept;
 
 private:
-    void update(Config const& config, duration lastFrameTime) noexcept;
-    backend::Handle<backend::HwTimerQuery> mQueries[POOL_COUNT];
-    duration mFrameTime{};
-    uint32_t mIndex = 0;
-    uint32_t mLast = 0;
-
-    std::array<FrameInfo, MAX_FRAMETIME_HISTORY> mFrameTimeHistory;
-    uint32_t mFrameTimeHistorySize = 0;
+    void denoiseFrameTime(Config const& config) noexcept;
+    struct Query {
+        backend::Handle<backend::HwTimerQuery> handle{};
+        FrameInfoImpl* pInfo = nullptr;
+    };
+    std::array<Query, POOL_COUNT> mQueries;
+    uint32_t mIndex = 0;                // index of current query
+    uint32_t mLast = 0;                 // index of oldest query still active
+    FrameInfoImpl* pFront = nullptr;    // the most recent slot with a valid frame time
+    CircularQueue<FrameInfoImpl, MAX_FRAMETIME_HISTORY> mFrameTimeHistory;
 };
 
 

filament/src/Renderer.cpp

@@ -14,11 +14,20 @@
  * limitations under the License.
  */
 
+#include <filament/Renderer.h>
+
 #include "details/Renderer.h"
 
 #include "details/Engine.h"
 #include "details/View.h"
 
+#include <utils/FixedCapacityVector.h>
+
+#include <utility>
+
+#include <stddef.h>
+#include <stdint.h>
+
 namespace filament {
 
 using namespace math;
@@ -93,4 +102,12 @@ void Renderer::setVsyncTime(uint64_t steadyClockTimeNano) noexcept {
     downcast(this)->setVsyncTime(steadyClockTimeNano);
 }
 
+utils::FixedCapacityVector<Renderer::FrameInfo> Renderer::getFrameInfoHistory(size_t historySize) const noexcept {
+    return downcast(this)->getFrameInfoHistory(historySize);
+}
+
+size_t Renderer::getMaxFrameHistorySize() const noexcept {
+    return downcast(this)->getMaxFrameHistorySize();
+}
+
 } // namespace filament

filament/src/details/Renderer.h

@@ -37,6 +37,7 @@
 
 #include <utils/compiler.h>
 #include <utils/Allocator.h>
+#include <utils/FixedCapacityVector.h>
 
 #include <math/vec4.h>
 
@@ -140,6 +141,14 @@ public:
         return mClearOptions;
     }
 
+    utils::FixedCapacityVector<Renderer::FrameInfo> getFrameInfoHistory(size_t historySize) const noexcept {
+        return mFrameInfoManager.getFrameInfoHistory(historySize);
+    }
+
+    size_t getMaxFrameHistorySize() const noexcept {
+        return MAX_FRAMETIME_HISTORY;
+    }
+
 private:
     friend class Renderer;
     using Command = RenderPass::Command;

filament/src/details/View.cpp

@@ -162,7 +162,7 @@ void FView::setDynamicLightingOptions(float zLightNear, float zLightFar) noexcep
 }
 
 float2 FView::updateScale(FEngine& engine,
-        FrameInfo const& info,
+        filament::details::FrameInfo const& info,
         Renderer::FrameRateOptions const& frameRateOptions,
         Renderer::DisplayInfo const& displayInfo) noexcept {
 

filament/src/details/View.h

@@ -283,7 +283,7 @@ public:
     }
 
     math::float2 updateScale(FEngine& engine,
-            FrameInfo const& info,
+            details::FrameInfo const& info,
             Renderer::FrameRateOptions const& frameRateOptions,
             Renderer::DisplayInfo const& displayInfo) noexcept;