mirror/openmw-tes3mp
1
0
Fork 1
mirror of https://github.com/TES3MP/openmw-tes3mp.git synced 2025-02-28 11:39:40 +00:00
Code Issues Releases Wiki Activity

Merge pull request #2006 from akortunov/recastlogging

Browse source 
Unify logging system for RecastNavigation
This commit is contained in:
Alexei Dobrohotov 2019-04-08 19:40:17 +03:00 committed by GitHub
commit 89776e2002
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
11 changed files with 42 additions and 162 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

3
apps/openmw/mwmechanics/pathfinding.cpp
View file

@ -327,8 +327,7 @@ namespace MWMechanics
} }
catch (const DetourNavigator::NavigatorException& exception) catch (const DetourNavigator::NavigatorException& exception)
{ {
DetourNavigator::log("PathFinder::buildPathByNavigator navigator exception: ", exception.what()); Log(Debug::Debug) << "Build path by navigator exception: \"" << exception.what()
Log(Debug::Verbose) << "Build path by navigator exception: \"" << exception.what()
<< "\" for \"" << actor.getClass().getName(actor) << "\" (" << actor.getBase() << "\" for \"" << actor.getClass().getName(actor) << "\" (" << actor.getBase()
<< ") from " << startPoint << " to " << endPoint << " with flags (" << ") from " << startPoint << " to " << endPoint << " with flags ("
<< DetourNavigator::WriteFlags {flags} << ")"; << DetourNavigator::WriteFlags {flags} << ")";

2
apps/openmw/mwworld/scene.cpp
View file

@ -327,7 +327,6 @@ namespace MWWorld
void Scene::unloadCell (CellStoreCollection::iterator iter) void Scene::unloadCell (CellStoreCollection::iterator iter)
{ {
Log(Debug::Info) << "Unloading cell " << (*iter)->getCell()->getDescription(); Log(Debug::Info) << "Unloading cell " << (*iter)->getCell()->getDescription();
DetourNavigator::log("unload cell ", (*iter)->getCell()->getDescription());
const auto navigator = MWBase::Environment::get().getWorld()->getNavigator(); const auto navigator = MWBase::Environment::get().getWorld()->getNavigator();
ListAndResetObjectsVisitor visitor; ListAndResetObjectsVisitor visitor;
@ -388,7 +387,6 @@ namespace MWWorld
if(result.second) if(result.second)
{ {
Log(Debug::Info) << "Loading cell " << cell->getCell()->getDescription(); Log(Debug::Info) << "Loading cell " << cell->getCell()->getDescription();
DetourNavigator::log("load cell ", cell->getCell()->getDescription());
float verts = ESM::Land::LAND_SIZE; float verts = ESM::Land::LAND_SIZE;
float worldsize = ESM::Land::REAL_SIZE; float worldsize = ESM::Land::REAL_SIZE;

3
apps/openmw/mwworld/worldimp.cpp
View file

@ -202,9 +202,6 @@ namespace MWWorld
navigatorSettings->mMaxClimb = MWPhysics::sStepSizeUp; navigatorSettings->mMaxClimb = MWPhysics::sStepSizeUp;
navigatorSettings->mMaxSlope = MWPhysics::sMaxSlope; navigatorSettings->mMaxSlope = MWPhysics::sMaxSlope;
navigatorSettings->mSwimHeightScale = mSwimHeightScale; navigatorSettings->mSwimHeightScale = mSwimHeightScale;
if (Settings::Manager::getBool("enable log", "Navigator"))
DetourNavigator::Log::instance().setSink(std::unique_ptr<DetourNavigator::FileSink>(
new DetourNavigator::FileSink(Settings::Manager::getString("log path", "Navigator"))));
DetourNavigator::RecastGlobalAllocator::init(); DetourNavigator::RecastGlobalAllocator::init();
mNavigator.reset(new DetourNavigator::NavigatorImpl(*navigatorSettings)); mNavigator.reset(new DetourNavigator::NavigatorImpl(*navigatorSettings));
} }

2
components/debug/debugging.cpp
View file

@ -76,6 +76,8 @@ namespace Debug
CurrentDebugLevel = Info; CurrentDebugLevel = Info;
else if (value == "VERBOSE") else if (value == "VERBOSE")
CurrentDebugLevel = Verbose; CurrentDebugLevel = Verbose;
else if (value == "DEBUG")
CurrentDebugLevel = Debug;
return; return;
} }

1
components/debug/debugging.hpp
View file

@ -83,6 +83,7 @@ namespace Debug
mColors[Warning] = Yellow; mColors[Warning] = Yellow;
mColors[Info] = Reset; mColors[Info] = Reset;
mColors[Verbose] = DarkGray; mColors[Verbose] = DarkGray;
mColors[Debug] = DarkGray;
mColors[NoLevel] = Reset; mColors[NoLevel] = Reset;
} }

5
components/debug/debuglog.hpp
View file

@ -14,9 +14,10 @@ namespace Debug
Warning = 2, Warning = 2,
Info = 3, Info = 3,
Verbose = 4, Verbose = 4,
Marker = Verbose, Debug = 5,
Marker = Debug,
NoLevel = 5 // Do not filter messages in this case NoLevel = 6 // Do not filter messages in this case
}; };
extern Level CurrentDebugLevel; extern Level CurrentDebugLevel;

28
components/detournavigator/asyncnavmeshupdater.cpp
View file

@ -92,7 +92,7 @@ namespace DetourNavigator
} }
} }
log("posted ", mJobs.size(), " jobs"); Log(Debug::Debug) << "Posted " << mJobs.size() << " navigator jobs";
if (!mJobs.empty()) if (!mJobs.empty())
mHasJob.notify_all(); mHasJob.notify_all();
@ -120,7 +120,7 @@ namespace DetourNavigator
void AsyncNavMeshUpdater::process() throw() void AsyncNavMeshUpdater::process() throw()
{ {
log("start process jobs"); Log(Debug::Debug) << "Start process navigator jobs";
while (!mShouldStop) while (!mShouldStop)
{ {
try try
@ -131,15 +131,15 @@ namespace DetourNavigator
} }
catch (const std::exception& e) catch (const std::exception& e)
{ {
DetourNavigator::log("AsyncNavMeshUpdater::process exception: ", e.what()); Log(Debug::Error) << "AsyncNavMeshUpdater::process exception: ", e.what();
} }
} }
log("stop process jobs"); Log(Debug::Debug) << "Stop navigator jobs processing";
} }
bool AsyncNavMeshUpdater::processJob(const Job& job) bool AsyncNavMeshUpdater::processJob(const Job& job)
{ {
log("process job for agent=", job.mAgentHalfExtents); Log(Debug::Debug) << "Process job for agent=(" << std::fixed << std::setprecision(2) << job.mAgentHalfExtents << ")";
const auto start = std::chrono::steady_clock::now(); const auto start = std::chrono::steady_clock::now();
@ -163,14 +163,14 @@ namespace DetourNavigator
using FloatMs = std::chrono::duration<float, std::milli>; using FloatMs = std::chrono::duration<float, std::milli>;
{ const auto locked = navMeshCacheItem->lockConst();
const auto locked = navMeshCacheItem->lockConst(); Log(Debug::Debug) << std::fixed << std::setprecision(2) <<
log("cache updated for agent=", job.mAgentHalfExtents, " status=", status, "Cache updated for agent=(" << job.mAgentHalfExtents << ")" <<
" generation=", locked->getGeneration(), " status=" << status <<
" revision=", locked->getNavMeshRevision(), " generation=" << locked->getGeneration() <<
" time=", std::chrono::duration_cast<FloatMs>(finish - start).count(), "ms", " revision=" << locked->getNavMeshRevision() <<
" total_time=", std::chrono::duration_cast<FloatMs>(finish - firstStart).count(), "ms"); " time=" << std::chrono::duration_cast<FloatMs>(finish - start).count() << "ms" <<
} " total_time=" << std::chrono::duration_cast<FloatMs>(finish - firstStart).count() << "ms";
return isSuccess(status); return isSuccess(status);
} }
@ -184,7 +184,7 @@ namespace DetourNavigator
mDone.notify_all(); mDone.notify_all();
return boost::none; return boost::none;
} }
log("got ", mJobs.size(), " jobs"); Log(Debug::Debug) << "Got " << mJobs.size() << " navigator jobs";
const auto job = mJobs.top(); const auto job = mJobs.top();
mJobs.pop(); mJobs.pop();
const auto pushed = mPushed.find(job.mAgentHalfExtents); const auto pushed = mPushed.find(job.mAgentHalfExtents);

99
components/detournavigator/debug.hpp
View file

@ -28,105 +28,6 @@ namespace DetourNavigator
class RecastMesh; class RecastMesh;
inline std::ostream& operator <<(std::ostream& stream, const std::chrono::steady_clock::time_point& value)
{
using float_s = std::chrono::duration<float, std::ratio<1>>;
return stream << std::fixed << std::setprecision(4)
<< std::chrono::duration_cast<float_s>(value.time_since_epoch()).count();
}
struct Sink
{
virtual ~Sink() = default;
virtual void write(const std::string& text) = 0;
};
class FileSink final : public Sink
{
public:
FileSink(std::string path)
: mPath(std::move(path))
{
mFile.exceptions(std::ios::failbit | std::ios::badbit);
}
void write(const std::string& text) override
{
if (!mFile.is_open())
{
mFile.open(mPath);
}
mFile << text << std::flush;
}
private:
std::string mPath;
std::ofstream mFile;
};
class StdoutSink final : public Sink
{
public:
void write(const std::string& text) override
{
std::cout << text << std::flush;
}
};
class Log
{
public:
void setSink(std::unique_ptr<Sink> sink)
{
*mSink.lock() = std::move(sink);
}
bool isEnabled()
{
return bool(*mSink.lockConst());
}
void write(const std::string& text)
{
const auto sink = mSink.lock();
if (*sink)
sink.get()->write(text);
}
static Log& instance()
{
static Log value;
return value;
}
private:
Misc::ScopeGuarded<std::unique_ptr<Sink>> mSink;
};
inline void write(std::ostream& stream)
{
stream << '\n';
}
template <class Head, class ... Tail>
void write(std::ostream& stream, const Head& head, const Tail& ... tail)
{
stream << head;
write(stream, tail ...);
}
template <class ... Ts>
void log(Ts&& ... values)
{
auto& log = Log::instance();
if (!log.isEnabled())
return;
std::ostringstream stream;
stream << '[' << std::chrono::steady_clock::now() << "] [" << std::this_thread::get_id() << "] ";
write(stream, std::forward<Ts>(values) ...);
log.write(stream.str());
}
void writeToFile(const RecastMesh& recastMesh, const std::string& pathPrefix, const std::string& revision); void writeToFile(const RecastMesh& recastMesh, const std::string& pathPrefix, const std::string& revision);
void writeToFile(const dtNavMesh& navMesh, const std::string& pathPrefix, const std::string& revision); void writeToFile(const dtNavMesh& navMesh, const std::string& pathPrefix, const std::string& revision);
} }

30
components/detournavigator/makenavmesh.cpp
View file

@ -17,6 +17,8 @@
#include <Recast.h> #include <Recast.h>
#include <RecastAlloc.h> #include <RecastAlloc.h>
#include <components/debug/debuglog.hpp>
#include <algorithm> #include <algorithm>
#include <iomanip> #include <iomanip>
#include <limits> #include <limits>
@ -486,23 +488,21 @@ namespace DetourNavigator
const std::vector<OffMeshConnection>& offMeshConnections, const Settings& settings, const std::vector<OffMeshConnection>& offMeshConnections, const Settings& settings,
const SharedNavMeshCacheItem& navMeshCacheItem, NavMeshTilesCache& navMeshTilesCache) const SharedNavMeshCacheItem& navMeshCacheItem, NavMeshTilesCache& navMeshTilesCache)
{ {
log("update NavMesh with mutiple tiles:", Log(Debug::Debug) << std::fixed << std::setprecision(2) <<
" agentHeight=", std::setprecision(std::numeric_limits<float>::max_exponent10), "Update NavMesh with multiple tiles:" <<
getHeight(settings, agentHalfExtents), " agentHeight=" << getHeight(settings, agentHalfExtents) <<
" agentMaxClimb=", std::setprecision(std::numeric_limits<float>::max_exponent10), " agentMaxClimb=" << getMaxClimb(settings) <<
getMaxClimb(settings), " agentRadius=" << getRadius(settings, agentHalfExtents) <<
" agentRadius=", std::setprecision(std::numeric_limits<float>::max_exponent10), " changedTile=(" << changedTile << ")" <<
getRadius(settings, agentHalfExtents), " playerTile=(" << playerTile << ")" <<
" changedTile=", changedTile, " changedTileDistance=" << getDistance(changedTile, playerTile);
" playerTile=", playerTile,
" changedTileDistance=", getDistance(changedTile, playerTile));
const auto params = *navMeshCacheItem->lockConst()->getImpl().getParams(); const auto params = *navMeshCacheItem->lockConst()->getImpl().getParams();
const osg::Vec3f origin(params.orig[0], params.orig[1], params.orig[2]); const osg::Vec3f origin(params.orig[0], params.orig[1], params.orig[2]);
if (!recastMesh) if (!recastMesh)
{ {
log("ignore add tile: recastMesh is null"); Log(Debug::Debug) << "Ignore add tile: recastMesh is null";
return navMeshCacheItem->lock()->removeTile(changedTile); return navMeshCacheItem->lock()->removeTile(changedTile);
} }
@ -517,13 +517,13 @@ namespace DetourNavigator
if (isEmpty(recastMeshBounds)) if (isEmpty(recastMeshBounds))
{ {
log("ignore add tile: recastMesh is empty"); Log(Debug::Debug) << "Ignore add tile: recastMesh is empty";
return navMeshCacheItem->lock()->removeTile(changedTile); return navMeshCacheItem->lock()->removeTile(changedTile);
} }
if (!shouldAddTile(changedTile, playerTile, std::min(settings.mMaxTilesNumber, params.maxTiles))) if (!shouldAddTile(changedTile, playerTile, std::min(settings.mMaxTilesNumber, params.maxTiles)))
{ {
log("ignore add tile: too far from player"); Log(Debug::Debug) << "Ignore add tile: too far from player";
return navMeshCacheItem->lock()->removeTile(changedTile); return navMeshCacheItem->lock()->removeTile(changedTile);
} }
@ -540,7 +540,7 @@ namespace DetourNavigator
if (!navMeshData.mValue) if (!navMeshData.mValue)
{ {
log("ignore add tile: NavMeshData is null"); Log(Debug::Debug) << "Ignore add tile: NavMeshData is null";
return navMeshCacheItem->lock()->removeTile(changedTile); return navMeshCacheItem->lock()->removeTile(changedTile);
} }
@ -557,7 +557,7 @@ namespace DetourNavigator
if (!cachedNavMeshData) if (!cachedNavMeshData)
{ {
log("cache overflow"); Log(Debug::Debug) << "Navigator cache overflow";
return navMeshCacheItem->lock()->updateTile(changedTile, std::move(navMeshData)); return navMeshCacheItem->lock()->updateTile(changedTile, std::move(navMeshData));
} }
} }

10
components/detournavigator/navmeshmanager.cpp
View file

@ -6,6 +6,8 @@
#include "navmeshcacheitem.hpp" #include "navmeshcacheitem.hpp"
#include "settings.hpp" #include "settings.hpp"
#include <components/debug/debuglog.hpp>
#include <DetourNavMesh.h> #include <DetourNavMesh.h>
namespace namespace
@ -95,7 +97,7 @@ namespace DetourNavigator
return; return;
mCache.insert(std::make_pair(agentHalfExtents, mCache.insert(std::make_pair(agentHalfExtents,
std::make_shared<GuardedNavMeshCacheItem>(makeEmptyNavMesh(mSettings), ++mGenerationCounter))); std::make_shared<GuardedNavMeshCacheItem>(makeEmptyNavMesh(mSettings), ++mGenerationCounter)));
log("cache add for agent=", agentHalfExtents); Log(Debug::Debug) << "cache add for agent=" << agentHalfExtents;
} }
bool NavMeshManager::reset(const osg::Vec3f& agentHalfExtents) bool NavMeshManager::reset(const osg::Vec3f& agentHalfExtents)
@ -193,9 +195,9 @@ namespace DetourNavigator
mAsyncNavMeshUpdater.post(agentHalfExtents, cached, playerTile, tilesToPost); mAsyncNavMeshUpdater.post(agentHalfExtents, cached, playerTile, tilesToPost);
if (changedTiles != mChangedTiles.end()) if (changedTiles != mChangedTiles.end())
changedTiles->second.clear(); changedTiles->second.clear();
log("cache update posted for agent=", agentHalfExtents, Log(Debug::Debug) << "cache update posted for agent=" << agentHalfExtents <<
" playerTile=", lastPlayerTile->second, " playerTile=" << lastPlayerTile->second <<
" recastMeshManagerRevision=", lastRevision); " recastMeshManagerRevision=" << lastRevision;
} }
void NavMeshManager::wait() void NavMeshManager::wait()

21
docs/source/reference/modding/settings/navigator.rst
View file

@ -79,27 +79,6 @@ Developer's settings
This section is for developers or anyone who wants to investigate how nav mesh system works in OpenMW. This section is for developers or anyone who wants to investigate how nav mesh system works in OpenMW.
enable log
----------
:Type: boolean
:Range: True/False
:Default: False
Enable debug log.
Detournavigator module will write own debug log into separate file.
Potentially decreases performance.
log path
--------
:Type: string
:Range: file system path
:Default: detournavigator.log
Write debug log to this file.
Try use tmpfs or any other in-memory file system to reduce performance impact.
enable write recast mesh to file enable write recast mesh to file
-------------------------------- --------------------------------