Use a generic logging system for RecastNavigation

pull/541/head
Andrei Kortunov 6 years ago
parent e9f6c11cc9
commit 14b756a692

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

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

@ -202,9 +202,6 @@ namespace MWWorld
navigatorSettings->mMaxClimb = MWPhysics::sStepSizeUp;
navigatorSettings->mMaxSlope = MWPhysics::sMaxSlope;
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();
mNavigator.reset(new DetourNavigator::NavigatorImpl(*navigatorSettings));
}

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

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

@ -14,9 +14,10 @@ namespace Debug
Warning = 2,
Info = 3,
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;

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

@ -28,105 +28,6 @@ namespace DetourNavigator
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 dtNavMesh& navMesh, const std::string& pathPrefix, const std::string& revision);
}

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

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

@ -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.
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
--------------------------------

Loading…
Cancel
Save