Skip to content
Snippets Groups Projects
Commit fbad49a1 authored by Olivier BICHLER's avatar Olivier BICHLER
Browse files

Added log context to help debugging

parent 9b85471f
No related branches found
No related tags found
No related merge requests found
...@@ -21,6 +21,12 @@ ...@@ -21,6 +21,12 @@
#include "aidge/utils/Attributes.hpp" #include "aidge/utils/Attributes.hpp"
namespace Aidge { namespace Aidge {
/**
* Helper to define a context anywhere, hidding the scoped variable name
* which has no relevance.
*/
#define AIDGE_LOG_CONTEXT(...) const Log::Context logContext_##__LINE__(__VA_ARGS__)
/** /**
* Aidge logging class, for displaying and file logging of events. * Aidge logging class, for displaying and file logging of events.
*/ */
...@@ -35,6 +41,18 @@ public: ...@@ -35,6 +41,18 @@ public:
Fatal Fatal
}; };
class Context {
public:
template <typename... Args>
Context(Args&&... args) {
Log::mContext.push_back(fmt::format(std::forward<Args>(args)...));
}
~Context() {
Log::mContext.pop_back();
}
};
/** /**
* Detailed messages for debugging purposes, providing information helpful * Detailed messages for debugging purposes, providing information helpful
* for developers to trace and identify issues. * for developers to trace and identify issues.
...@@ -144,6 +162,7 @@ private: ...@@ -144,6 +162,7 @@ private:
static Level mFileLevel; static Level mFileLevel;
static std::string mFileName; static std::string mFileName;
static std::unique_ptr<FILE, decltype(&std::fclose)> mFile; static std::unique_ptr<FILE, decltype(&std::fclose)> mFile;
static std::vector<std::string> mContext;
}; };
} }
......
...@@ -139,6 +139,8 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S ...@@ -139,6 +139,8 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S
bool isRunnable = true; bool isRunnable = true;
for (IOIndex_t inputIdx = 0; inputIdx < consumer->nbInputs(); ++inputIdx) { for (IOIndex_t inputIdx = 0; inputIdx < consumer->nbInputs(); ++inputIdx) {
AIDGE_LOG_CONTEXT("Consumer node {} input #{}", namePtrTable.at(consumer), inputIdx);
if ((consumer->getOperator()->getNbConsumedData(inputIdx) + consumer->getOperator()->getNbRequiredData(inputIdx)) > if ((consumer->getOperator()->getNbConsumedData(inputIdx) + consumer->getOperator()->getNbRequiredData(inputIdx)) >
getNbAvailableData(consumer, inputIdx)) { getNbAvailableData(consumer, inputIdx)) {
Log::debug(" not runnable: C{} + R{} > P{} for input #{}", Log::debug(" not runnable: C{} + R{} > P{} for input #{}",
...@@ -205,6 +207,8 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S ...@@ -205,6 +207,8 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S
// have been exhausted. // have been exhausted.
bool isStillConsumer = false; bool isStillConsumer = false;
for (IOIndex_t inputIdx = 0; inputIdx < consumer->nbInputs(); ++inputIdx) { for (IOIndex_t inputIdx = 0; inputIdx < consumer->nbInputs(); ++inputIdx) {
AIDGE_LOG_CONTEXT("Consumer node {} input #{}", namePtrTable.at(consumer), inputIdx);
if (consumer->getOperator()->getNbConsumedData(inputIdx) < if (consumer->getOperator()->getNbConsumedData(inputIdx) <
getNbAvailableData(consumer, inputIdx)) { getNbAvailableData(consumer, inputIdx)) {
Log::debug(" still consumer: C{} < P{} for input #{}", Log::debug(" still consumer: C{} < P{} for input #{}",
...@@ -226,6 +230,9 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S ...@@ -226,6 +230,9 @@ std::vector<std::shared_ptr<Aidge::Scheduler::StaticSchedulingElement>> Aidge::S
IOIndex_t inputIdx = 0; IOIndex_t inputIdx = 0;
for (const auto& childParent : child->getParents()) { for (const auto& childParent : child->getParents()) {
if (childParent == consumer) { if (childParent == consumer) {
AIDGE_LOG_CONTEXT("Consumer node {} input #{} / Producer node {} output #{}",
namePtrTable.at(child), inputIdx, namePtrTable.at(consumer), outId);
if (child->getOperator()->getNbConsumedData(inputIdx) < consumer->getOperator()->getNbProducedData(outId)) { if (child->getOperator()->getNbConsumedData(inputIdx) < consumer->getOperator()->getNbProducedData(outId)) {
isProducer = true; isProducer = true;
break; break;
...@@ -645,32 +652,36 @@ Aidge::Scheduler::PriorProducersConsumers Aidge::Scheduler::getPriorProducersCon ...@@ -645,32 +652,36 @@ Aidge::Scheduler::PriorProducersConsumers Aidge::Scheduler::getPriorProducersCon
IOIndex_t inputIdx = 0; IOIndex_t inputIdx = 0;
for (const auto& parent : node->inputs()) { for (const auto& parent : node->inputs()) {
if (parent.first && if (parent.first) {
(node->getOperator()->getNbConsumedData(inputIdx) + node->getOperator()->getNbRequiredData(inputIdx)) > AIDGE_LOG_CONTEXT("Producer node {} (of type {}) output #{}",
parent.first->getOperator()->getNbProducedData(parent.second)) parent.first->name(), parent.first->type(), parent.second);
{
if (!mGraphView->inView(parent.first)) { if ((node->getOperator()->getNbConsumedData(inputIdx) + node->getOperator()->getNbRequiredData(inputIdx)) >
// Do not schedule prior outside the current graph! parent.first->getOperator()->getNbProducedData(parent.second))
return PriorProducersConsumers(); {
} if (!mGraphView->inView(parent.first)) {
// Do not schedule prior outside the current graph!
if (parent.first->type() == Producer_Op::Type) { return PriorProducersConsumers();
prior.requiredProducers.insert(parent.first); }
prior.priorConsumers.insert(node);
}
else if (parent.first->type() == Memorize_Op::Type) {
// Break cycles
return PriorProducersConsumers();
}
else {
const auto& parentPrior = getPriorProducersConsumers(parent.first);
if (!parentPrior.isPrior) { if (parent.first->type() == Producer_Op::Type) {
prior.requiredProducers.insert(parent.first);
prior.priorConsumers.insert(node);
}
else if (parent.first->type() == Memorize_Op::Type) {
// Break cycles
return PriorProducersConsumers(); return PriorProducersConsumers();
} }
else { else {
prior.requiredProducers.insert(parentPrior.requiredProducers.cbegin(), parentPrior.requiredProducers.cend()); const auto& parentPrior = getPriorProducersConsumers(parent.first);
prior.priorConsumers.insert(parentPrior.priorConsumers.cbegin(), parentPrior.priorConsumers.cend());
if (!parentPrior.isPrior) {
return PriorProducersConsumers();
}
else {
prior.requiredProducers.insert(parentPrior.requiredProducers.cbegin(), parentPrior.requiredProducers.cend());
prior.priorConsumers.insert(parentPrior.priorConsumers.cbegin(), parentPrior.priorConsumers.cend());
}
} }
} }
} }
......
...@@ -47,6 +47,7 @@ std::string Aidge::Log::mFileName = []() { ...@@ -47,6 +47,7 @@ std::string Aidge::Log::mFileName = []() {
return std::string(); return std::string();
}(); }();
std::unique_ptr<FILE, decltype(&std::fclose)> Aidge::Log::mFile {nullptr, nullptr}; std::unique_ptr<FILE, decltype(&std::fclose)> Aidge::Log::mFile {nullptr, nullptr};
std::vector<std::string> Aidge::Log::mContext;
void Aidge::Log::log(Level level, const std::string& msg) { void Aidge::Log::log(Level level, const std::string& msg) {
if (level >= mConsoleLevel) { if (level >= mConsoleLevel) {
...@@ -61,6 +62,10 @@ void Aidge::Log::log(Level level, const std::string& msg) { ...@@ -61,6 +62,10 @@ void Aidge::Log::log(Level level, const std::string& msg) {
: (level == Fatal) ? fmt::bg(fmt::color::red) : (level == Fatal) ? fmt::bg(fmt::color::red)
: fmt::text_style(); : fmt::text_style();
for (const auto& context : mContext) {
fmt::println("Context: {}", context);
}
fmt::println("{}", fmt::styled(msg, modifier)); fmt::println("{}", fmt::styled(msg, modifier));
} }
...@@ -69,6 +74,10 @@ void Aidge::Log::log(Level level, const std::string& msg) { ...@@ -69,6 +74,10 @@ void Aidge::Log::log(Level level, const std::string& msg) {
initFile(mFileName); initFile(mFileName);
} }
for (const auto& context : mContext) {
fmt::println("Context: {}", context);
}
fmt::println(mFile.get(), msg); fmt::println(mFile.get(), msg);
} }
} }
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment