wsd/ClientSession.cpp | 5 +--- wsd/DocumentBroker.cpp | 14 +++++++---- wsd/TileCache.cpp | 61 +++++++++++++++++++++++++++---------------------- wsd/TileCache.hpp | 13 ++++------ wsd/TileDesc.hpp | 8 ++++++ 5 files changed, 59 insertions(+), 42 deletions(-)
New commits: commit f56fd1838895cb9d2db29c80bcf700795dda1e0a Author: Michael Meeks <michael.me...@collabora.com> AuthorDate: Fri Aug 7 17:36:56 2020 +0100 Commit: Jan Holesovsky <ke...@collabora.com> CommitDate: Tue Aug 11 19:00:57 2020 +0200 TileCache: cleanup debug, propagate now more helpfully & fix staleness. Stale tiles were still being counted, unhelpfully. Avoid doing lots of ::now() calls, and yet detect this. Change-Id: Ib1e4b2f1968c1994849bb23ec54e28f6706230ee Reviewed-on: https://gerrit.libreoffice.org/c/online/+/100347 Tested-by: Jenkins Reviewed-by: Michael Meeks <michael.me...@collabora.com> Reviewed-on: https://gerrit.libreoffice.org/c/online/+/100506 Tested-by: Jan Holesovsky <ke...@collabora.com> Reviewed-by: Jan Holesovsky <ke...@collabora.com> diff --git a/wsd/ClientSession.cpp b/wsd/ClientSession.cpp index 3173154d1..b24f9b655 100644 --- a/wsd/ClientSession.cpp +++ b/wsd/ClientSession.cpp @@ -1573,9 +1573,8 @@ bool ClientSession::forwardToClient(const std::shared_ptr<Message>& payload) void ClientSession::enqueueSendMessage(const std::shared_ptr<Message>& data) { const std::shared_ptr<DocumentBroker> docBroker = _docBroker.lock(); - // If in the correct thread - no need for wakeups. - if (docBroker) - docBroker->assertCorrectThread(); + LOG_CHECK_RET(docBroker && "Null DocumentBroker instance", ); + docBroker->assertCorrectThread(); const std::string command = data->firstToken(); std::unique_ptr<TileDesc> tile; diff --git a/wsd/DocumentBroker.cpp b/wsd/DocumentBroker.cpp index 15003be34..03f23c08a 100644 --- a/wsd/DocumentBroker.cpp +++ b/wsd/DocumentBroker.cpp @@ -1658,6 +1658,7 @@ size_t DocumentBroker::getMemorySize() const _sessions.size() * sizeof(ClientSession); } +// Expected to be legacy, ~all new requests are tilecombinedRequests void DocumentBroker::handleTileRequest(TileDesc& tile, const std::shared_ptr<ClientSession>& session) { @@ -1676,17 +1677,18 @@ void DocumentBroker::handleTileRequest(TileDesc& tile, return; } + auto now = std::chrono::steady_clock::now(); if (tile.getBroadcast()) { for (auto& it: _sessions) { if (!it.second->inWaitDisconnected()) - tileCache().subscribeToTileRendering(tile, it.second); + tileCache().subscribeToTileRendering(tile, it.second, now); } } else { - tileCache().subscribeToTileRendering(tile, session); + tileCache().subscribeToTileRendering(tile, session, now); } // Forward to child to render. @@ -1865,6 +1867,8 @@ void DocumentBroker::sendRequestedTiles(const std::shared_ptr<ClientSession>& se // Drop tiles which we are waiting for too long session->removeOutdatedTilesOnFly(); + auto now = std::chrono::steady_clock::now(); + // All tiles were processed on client side that we sent last time, so we can send // a new batch of tiles which was invalidated / requested in the meantime std::deque<TileDesc>& requestedTiles = session->getRequestedTiles(); @@ -1872,7 +1876,7 @@ void DocumentBroker::sendRequestedTiles(const std::shared_ptr<ClientSession>& se { size_t delayedTiles = 0; std::vector<TileDesc> tilesNeedsRendering; - size_t beingRendered = _tileCache->countTilesBeingRenderedForSession(session); + size_t beingRendered = _tileCache->countTilesBeingRenderedForSession(session, now); while (session->getTilesOnFlyCount() + beingRendered < tilesOnFlyUpperLimit && !requestedTiles.empty() && // If we delayed all tiles we don't send any tile (we will when next tileprocessed message arrives) @@ -1902,14 +1906,14 @@ void DocumentBroker::sendRequestedTiles(const std::shared_ptr<ClientSession>& se else { // Not cached, needs rendering. - if (!tileCache().hasTileBeingRendered(tile) || // There is no in progress rendering of the given tile + if (!tileCache().hasTileBeingRendered(tile, &now) || // There is no in progress rendering of the given tile tileCache().getTileBeingRenderedVersion(tile) < tile.getVersion()) // We need a newer version { tile.setVersion(++_tileVersion); tilesNeedsRendering.push_back(tile); _debugRenderedTileCount++; } - tileCache().subscribeToTileRendering(tile, session); + tileCache().subscribeToTileRendering(tile, session, now); beingRendered++; } requestedTiles.pop_front(); diff --git a/wsd/TileCache.cpp b/wsd/TileCache.cpp index 8be7b9aff..e1cdefe8d 100644 --- a/wsd/TileCache.cpp +++ b/wsd/TileCache.cpp @@ -70,19 +70,19 @@ void TileCache::clear() /// rendering latency. struct TileCache::TileBeingRendered { - explicit TileBeingRendered(const TileDesc& tile) - : _startTime(std::chrono::steady_clock::now()) - , _tile(tile) - { - } + explicit TileBeingRendered(const TileDesc& tile, const std::chrono::steady_clock::time_point &now) + : _startTime(now), _tile(tile) { } const TileDesc& getTile() const { return _tile; } int getVersion() const { return _tile.getVersion(); } void setVersion(int version) { _tile.setVersion(version); } std::chrono::steady_clock::time_point getStartTime() const { return _startTime; } - double getElapsedTimeMs() const { return std::chrono::duration_cast<std::chrono::milliseconds> - (std::chrono::steady_clock::now() - _startTime).count(); } + double getElapsedTimeMs(const std::chrono::steady_clock::time_point *now = nullptr) const + { return std::chrono::duration_cast<std::chrono::milliseconds> + ((now ? *now : std::chrono::steady_clock::now()) - _startTime).count(); } + bool isStale(const std::chrono::steady_clock::time_point *now = nullptr) const + { return getElapsedTimeMs(now) > COMMAND_TIMEOUT_MS; } std::vector<std::weak_ptr<ClientSession>>& getSubscribers() { return _subscribers; } void dumpState(std::ostream& os); @@ -93,11 +93,15 @@ private: TileDesc _tile; }; -size_t TileCache::countTilesBeingRenderedForSession(const std::shared_ptr<ClientSession>& session) +size_t TileCache::countTilesBeingRenderedForSession(const std::shared_ptr<ClientSession>& session, + const std::chrono::steady_clock::time_point &now) { size_t count = 0; for (auto& it : _tilesBeingRendered) { + if (it.second->isStale(&now)) + continue; + for (auto& s : it.second->getSubscribers()) { if (s.lock() == session) @@ -108,6 +112,16 @@ size_t TileCache::countTilesBeingRenderedForSession(const std::shared_ptr<Client return count; } +bool TileCache::hasTileBeingRendered(const TileDesc& tileDesc, const std::chrono::steady_clock::time_point *now) const +{ + const auto it = _tilesBeingRendered.find(tileDesc); + if (it == _tilesBeingRendered.end()) + return false; + + /// did we stall ? if so re-issue. + return !now ? true : !it->second->isStale(now); +} + std::shared_ptr<TileCache::TileBeingRendered> TileCache::findTileBeingRendered(const TileDesc& tileDesc) { assertCorrectThread(); @@ -397,47 +411,40 @@ bool TileCache::intersectsTile(const TileDesc &tileDesc, int part, int x, int y, } // FIXME: to be further simplified when we centralize tile messages. -void TileCache::subscribeToTileRendering(const TileDesc& tile, const std::shared_ptr<ClientSession>& subscriber) +void TileCache::subscribeToTileRendering(const TileDesc& tile, const std::shared_ptr<ClientSession>& subscriber, + const std::chrono::steady_clock::time_point &now) { - std::ostringstream oss; - oss << '(' << tile.getNormalizedViewId() << ',' << tile.getPart() << ',' << tile.getTilePosX() << ',' << tile.getTilePosY() << ')'; - const std::string name = oss.str(); - assertCorrectThread(); std::shared_ptr<TileBeingRendered> tileBeingRendered = findTileBeingRendered(tile); if (tileBeingRendered) { + if (tileBeingRendered->isStale(&now)) + LOG_DBG("Painting stalled; need to re-issue on tile " << tile.debugName()); + for (const auto &s : tileBeingRendered->getSubscribers()) { if (s.lock().get() == subscriber.get()) { - LOG_DBG("Redundant request to subscribe on tile " << name); + LOG_DBG("Redundant request to subscribe on tile " << tile.debugName()); tileBeingRendered->setVersion(tile.getVersion()); return; } } - LOG_DBG("Subscribing " << subscriber->getName() << " to tile " << name << " which has " << + LOG_DBG("Subscribing " << subscriber->getName() << " to tile " << tile.debugName() << " which has " << tileBeingRendered->getSubscribers().size() << " subscribers already."); tileBeingRendered->getSubscribers().push_back(subscriber); - - const auto duration = (std::chrono::steady_clock::now() - tileBeingRendered->getStartTime()); - if (std::chrono::duration_cast<std::chrono::milliseconds>(duration).count() > COMMAND_TIMEOUT_MS) - { - // Tile painting has stalled. Reissue. - tileBeingRendered->setVersion(tile.getVersion()); - } } else { - LOG_DBG("Subscribing " << subscriber->getName() << " to tile " << name << + LOG_DBG("Subscribing " << subscriber->getName() << " to tile " << tile.debugName() << " ver=" << tile.getVersion() << " which has no subscribers " << tile.serialize()); assert(_tilesBeingRendered.find(tile) == _tilesBeingRendered.end()); - tileBeingRendered = std::make_shared<TileBeingRendered>(tile); + tileBeingRendered = std::make_shared<TileBeingRendered>(tile, now); tileBeingRendered->getSubscribers().push_back(subscriber); _tilesBeingRendered[tile] = tileBeingRendered; } @@ -446,10 +453,10 @@ void TileCache::subscribeToTileRendering(const TileDesc& tile, const std::shared void TileCache::registerTileBeingRendered(const TileDesc& tile) { std::shared_ptr<TileBeingRendered> tileBeingRendered = findTileBeingRendered(tile); + auto now = std::chrono::steady_clock::now(); if (tileBeingRendered) { - const auto duration = (std::chrono::steady_clock::now() - tileBeingRendered->getStartTime()); - if (std::chrono::duration_cast<std::chrono::milliseconds>(duration).count() > COMMAND_TIMEOUT_MS) + if (tileBeingRendered->isStale(&now)) { // Tile painting has stalled. Reissue. tileBeingRendered->setVersion(tile.getVersion()); @@ -459,7 +466,7 @@ void TileCache::registerTileBeingRendered(const TileDesc& tile) { assert(_tilesBeingRendered.find(tile) == _tilesBeingRendered.end()); - tileBeingRendered = std::make_shared<TileBeingRendered>(tile); + tileBeingRendered = std::make_shared<TileBeingRendered>(tile, now); _tilesBeingRendered[tile] = tileBeingRendered; } } diff --git a/wsd/TileCache.hpp b/wsd/TileCache.hpp index 3fecd7a1b..e4e54fc4e 100644 --- a/wsd/TileCache.hpp +++ b/wsd/TileCache.hpp @@ -81,7 +81,8 @@ public: /// Subscribes if no subscription exists and returns the version number. /// Otherwise returns 0 to signify a subscription exists. - void subscribeToTileRendering(const TileDesc& tile, const std::shared_ptr<ClientSession>& subscriber); + void subscribeToTileRendering(const TileDesc& tile, const std::shared_ptr<ClientSession>& subscriber, + const std::chrono::steady_clock::time_point& now); /// Create the TileBeingRendered object for the given tile indicating that the tile was sent to /// the kit for rendering. Note: subscribeToTileRendering calls this internally, so you don't need @@ -126,13 +127,11 @@ public: void forgetTileBeingRendered(const std::shared_ptr<TileCache::TileBeingRendered>& tileBeingRendered); double getTileBeingRenderedElapsedTimeMs(const TileDesc &tileDesc) const; - size_t countTilesBeingRenderedForSession(const std::shared_ptr<ClientSession>& session); - inline bool hasTileBeingRendered(const TileDesc& tileDesc) const - { - return _tilesBeingRendered.find(tileDesc) != _tilesBeingRendered.end(); - } + size_t countTilesBeingRenderedForSession(const std::shared_ptr<ClientSession>& session, + const std::chrono::steady_clock::time_point& now); + bool hasTileBeingRendered(const TileDesc& tileDesc, const std::chrono::steady_clock::time_point *now = nullptr) const; - int getTileBeingRenderedVersion(const TileDesc& tileDesc); + int getTileBeingRenderedVersion(const TileDesc& tileDesc); /// Set the high watermark for tilecache size void setMaxCacheSize(size_t cacheSize); diff --git a/wsd/TileDesc.hpp b/wsd/TileDesc.hpp index cec900d50..28ecc4256 100644 --- a/wsd/TileDesc.hpp +++ b/wsd/TileDesc.hpp @@ -193,6 +193,14 @@ public: return oss.str(); } + /// short name for a tile for debugging. + std::string debugName() const + { + std::ostringstream oss; + oss << '(' << getNormalizedViewId() << ',' << getPart() << ',' << getTilePosX() << ',' << getTilePosY() << ')'; + return oss.str(); + } + /// Deserialize a TileDesc from a tokenized string. static TileDesc parse(const StringVector& tokens) { _______________________________________________ Libreoffice-commits mailing list libreoffice-comm...@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/libreoffice-commits