Commit 27780075 authored by Nicholas Milef's avatar Nicholas Milef Committed by Alexis Girault
Browse files

ENH: Added general purpose logging system


Co-Authored-by: Alexis Girault's avatarAlexis Girault <alexis.girault@kitware.com>
parent a177c405
/*=========================================================================
Library: iMSTK
Copyright (c) Kitware, Inc. & Center for Modeling, Simulation,
& Imaging in Medicine, Rensselaer Polytechnic Institute.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0.txt
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
=========================================================================*/
#include "imstkLogUtility.h"
namespace imstk
{
stdSink::FG_Color
stdSink::GetColor(const LEVELS level) const
{
if (level.value == WARNING.value) return YELLOW;
if (level.value == DEBUG.value) return GREEN;
if (level.value == FATAL.value) return RED;
return WHITE;
}
void
stdSink::ReceiveLogMessage(g3::LogMessageMover logEntry)
{
auto level = logEntry.get()._level;
auto message = logEntry.get().message();
#ifndef WIN32
auto color = GetColor(level);
std::cout << "\033[" << color << "m"
<< message
<< "\033[m" << std::endl;
#else
if (level.value == WARNING.value || level.value == FATAL.value)
{
std::cerr << message << std::endl;
}
else
{
std::cout << message << std::endl;
}
#endif
}
void
LogUtility::createLogger(std::string name, std::string path)
{
m_g3logWorker = g3::LogWorker::createLogWorker();
m_fileSinkHandle = m_g3logWorker->addDefaultLogger(name, path);
m_stdSinkHandle = m_g3logWorker->addSink(
std2::make_unique<stdSink>(), &stdSink::ReceiveLogMessage);
g3::initializeLogging(m_g3logWorker.get());
}
}
\ No newline at end of file
/*=========================================================================
Library: iMSTK
Copyright (c) Kitware, Inc. & Center for Modeling, Simulation,
& Imaging in Medicine, Rensselaer Polytechnic Institute.
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0.txt
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
=========================================================================*/
#ifndef imstkLogUtility_h
#define imstkLogUtility_h
#include "g3log/logmessage.hpp"
#include "g3log/logworker.hpp"
#include "imstkLogger.h"
namespace imstk
{
///
/// \struct stdSink
///
/// \brief
///
struct stdSink
{
// Linux xterm color
// http://stackoverflow.com/questions/2616906/how-do-i-output-coloured-text-to-a-linux-terminal
enum FG_Color { YELLOW = 33, RED = 31, GREEN = 32, WHITE = 97 };
FG_Color GetColor(const LEVELS level) const;
void ReceiveLogMessage(g3::LogMessageMover logEntry);
};
// Available through namespace
extern void Log(std::string name, std::string message);
///
/// \struct LogManager
///
/// \brief
///
struct LogManager {
std::map<std::string, Logger *> loggers;
std::map<std::string, std::thread *> loggerThreads;
};
///
/// \struct LogUtility
///
/// \brief
///
struct LogUtility
{
void createLogger(std::string name, std::string path);
std::unique_ptr<g3::LogWorker> m_g3logWorker;
std::unique_ptr<g3::SinkHandle<g3::FileSink> >m_fileSinkHandle;
std::unique_ptr<g3::SinkHandle<stdSink> > m_stdSinkHandle;
};
}
#endif
\ No newline at end of file
......@@ -20,51 +20,159 @@
=========================================================================*/
#include "imstkLogger.h"
#include <cstring>
namespace imstk
{
stdSink::FG_Color
stdSink::GetColor(const LEVELS level) const
Logger::Logger(std::string filename)
{
if (level.value == WARNING.value) return YELLOW;
if (level.value == DEBUG.value) return GREEN;
if (level.value == FATAL.value) return RED;
return WHITE;
m_filename = filename + this->getCurrentTimeFormatted() + ".log";
m_mutex = new std::mutex();
m_thread = new std::thread(Logger::eventLoop, this);
}
Logger::~Logger()
{
delete m_mutex;
m_thread->join();
delete m_thread;
}
std::string
Logger::getCurrentTimeFormatted() {
time_t now = time(0);
int year = gmtime(&now)->tm_year + 1900;
int day = gmtime(&now)->tm_mday;
int month = gmtime(&now)->tm_mon;
int hour = gmtime(&now)->tm_hour;
int min = gmtime(&now)->tm_min;
int sec = gmtime(&now)->tm_sec;
std::string year_string = std::to_string(year);
std::string day_string = std::to_string(day);
if (day < 10)
{
day_string = "0" + day_string;
}
std::string month_string = std::to_string(month);
if (month < 10)
{
month_string = "0" + month_string;
}
std::string hour_string = std::to_string(hour);
if (hour < 10)
{
hour_string = "0" + hour_string;
}
std::string min_string = std::to_string(min);
if (min < 10)
{
min_string = "0" + min_string;
}
std::string sec_string = std::to_string(sec);
if (sec < 10)
{
sec_string = "0" + sec_string;
}
return year_string + day_string + month_string + "-" + hour_string + min_string + sec_string;
}
void
Logger::eventLoop(Logger * logger)
{
std::ofstream file(logger->m_filename);
char buffer[1024];
std::fill_n(buffer, 1024, '\0');
while (logger->m_running) {
std::unique_lock<std::mutex> ul(*logger->m_mutex);
logger->m_condition.wait(ul, [logger]{return logger->m_changed; });
if (!logger->m_running) {
logger->m_changed = false;
ul.unlock();
break;
}
std::strcpy(buffer, logger->m_message.c_str());
logger->m_changed = false;
ul.unlock();
logger->m_condition.notify_one();
file << buffer << "\n";
}
file.close();
logger->m_condition.notify_one();
}
void
stdSink::ReceiveLogMessage(g3::LogMessageMover logEntry)
Logger::log(std::string message, bool prependTime /* = false */)
{
auto level = logEntry.get()._level;
auto message = logEntry.get().message();
#ifndef WIN32
auto color = GetColor(level);
std::cout << "\033[" << color << "m"
<< message
<< "\033[m" << std::endl;
#else
if (level.value == WARNING.value || level.value == FATAL.value)
if (prependTime)
{
m_message = this->getCurrentTimeFormatted() + " ";
}
m_message += message;
// Safely setting the change state
{
std::cerr << message << std::endl;
std::lock_guard<std::mutex> guard(*m_mutex);
m_changed = true;
}
else
m_condition.notify_one();
std::unique_lock<std::mutex> ul(*m_mutex);
m_condition.wait(ul, [this]{return !m_changed; });
ul.unlock();
}
bool
Logger::readyForLoggingWithFrequency()
{
long long currentMilliseconds = std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock().now().time_since_epoch()).count();
if (currentMilliseconds - m_lastLogTime > m_period)
{
std::cout << message << std::endl;
return true;
}
#endif
return false;
}
void
Logger::updateLogTime()
{
m_lastLogTime = std::chrono::duration_cast<std::chrono::milliseconds>(std::chrono::system_clock().now().time_since_epoch()).count();
}
void
Logger::setFrequency(int frequency)
{
m_frequency = frequency;
m_period = 1000 / m_frequency;
}
int
Logger::getFrequency()
{
return m_frequency;
}
void
LogUtility::createLogger(std::string name, std::string path)
Logger::shutdown()
{
m_g3logWorker = g3::LogWorker::createLogWorker();
m_fileSinkHandle = m_g3logWorker->addDefaultLogger(name, path);
m_stdSinkHandle = m_g3logWorker->addSink(
std2::make_unique<stdSink>(), &stdSink::ReceiveLogMessage);
g3::initializeLogging(m_g3logWorker.get());
// Safely setting the running state
{
std::lock_guard<std::mutex> guard(*m_mutex);
m_changed = true;
m_running = false;
}
m_condition.notify_one();
std::unique_lock<std::mutex> ul(*m_mutex);
m_condition.wait(ul, [this]{return !m_changed; });
ul.unlock();
}
}
\ No newline at end of file
}
......@@ -19,45 +19,98 @@
=========================================================================*/
#ifndef imstkLogUtility_h
#define imstkLogUtility_h
#ifndef imstkLogger_h
#define imstkLogger_h
#include <string>
#include <iostream>
#include "g3log/logmessage.hpp"
#include "g3log/logworker.hpp"
#include <fstream>
#include <mutex>
#include <map>
#include <thread>
#include <condition_variable>
#include <memory>
namespace imstk
{
///
/// \struct stdSink
/// \class Logger
///
/// \brief
/// \brief The logger class. This class can be instantiated multiple times.
/// It runs on a seperate thread and buffers the output using system
/// internal buffering to maintain good performance. If the program crashes,
/// then unflushed content will NOT be preserved.
///
struct stdSink
class Logger
{
// Linux xterm color
// http://stackoverflow.com/questions/2616906/how-do-i-output-coloured-text-to-a-linux-terminal
enum FG_Color { YELLOW = 33, RED = 31, GREEN = 32, WHITE = 97 };
public:
///
/// \brief Logger instantiation method
/// \params filename this name will be used in the file name of the log file
///
Logger(std::string filename);
~Logger();
FG_Color GetColor(const LEVELS level) const;
void ReceiveLogMessage(g3::LogMessageMover logEntry);
};
///
/// \brief Log one line.
/// \params message the message to log
/// \params prependTime defines if the current time is prepended to
/// the message. Disabled by default.
///
void log(std::string message, bool prependTime = false);
///
/// \struct LogUtility
///
/// \brief
///
struct LogUtility
{
void createLogger(std::string name, std::string path);
///
/// \brief Sets the frequency in Hz. This also updates the period.
/// \params frequency the frequency in Hz
///
void setFrequency(int frequency);
///
/// \brief Log one formatted line with four data points.
/// \returns frequency in Hz
///
int getFrequency();
///
/// \brief Checks if outside of one period from last log time.
/// This method does NOT update log time.
/// \returns true when outside of one period from last log time
///
bool readyForLoggingWithFrequency();
///
/// \brief Updates the last log time
///
void updateLogTime();
///
/// \brief Logger thread loop
/// \params logger a handle for the logger
///
static void eventLoop(Logger * logger);
///
/// \brief Shuts down and cleans up logger safely
///
void shutdown();
private:
static std::string getCurrentTimeFormatted();
// Mutex for performance reasons
std::mutex* m_mutex;
std::string m_message;
bool m_changed = false;
bool m_running = true;
int m_frequency = 30;
int m_period = 1000 / 30;
long long m_lastLogTime = 0;
std::unique_ptr<g3::LogWorker> m_g3logWorker;
std::unique_ptr<g3::SinkHandle<g3::FileSink> >m_fileSinkHandle;
std::unique_ptr<g3::SinkHandle<stdSink> > m_stdSinkHandle;
std::string m_filename;
std::thread* m_thread;
std::condition_variable m_condition;
};
}
......
......@@ -32,7 +32,7 @@
#include "imstkModule.h"
#include "imstkSceneManager.h"
#include "imstkVTKViewer.h"
#include "imstkLogger.h"
#include "imstkLogUtility.h"
namespace imstk
{
......
......@@ -78,6 +78,7 @@
// logger
#include "g3log/g3log.hpp"
#include "imstkLogger.h"
// imstk utilities
#include "imstkPlotterUtils.h"
......@@ -189,7 +190,7 @@ int main()
Test devices, controllers
------------------*/
//testObjectController();
//testTwoFalcons();
testTwoFalcons();
//testCameraController();
//testTwoOmnis();
//testLapToolController();
......@@ -200,7 +201,7 @@ int main()
------------------*/
//testScenesManagement();
//testVectorPlotters();
testVirtualCoupling();
//testVirtualCoupling();
return 0;
......@@ -596,28 +597,53 @@ void testTwoFalcons()
cam->setPosition(Vec3d(0, 18, 40));
// Print device tracking info (callback)
Logger* logger;
unsigned int displayCpt = 0;
auto postUpdateFoo = [&displayCpt](Module* module)
auto postInitFoo = [&logger](Module* module)
{
logger = new Logger(module->getName());
logger->setFrequency(5);
};
auto postUpdateFoo = [&displayCpt, &logger](Module* module)
{
// Show every 1000 updates
if (++displayCpt < 1000)
{
return;
}
displayCpt = 0;
// Print position & velocity
// NB: Could write this in a file, or store it in an array
auto client = static_cast<VRPNDeviceClient*>(module);
Vec3d p = client->getPosition();
Vec3d v = client->getVelocity();
std::cout << "\r-- " << module->getName()
<< " pos = (" << p[0] << ", " << p[1] << ", " << p[2] << ") "
<< " vel = (" << v[0] << ", " << v[1] << ", " << v[2] << ")"
<< std::flush;
std::string message =
" pos = (" + std::to_string(p[0])
+ ", " + std::to_string(p[1])
+ ", " + std::to_string(p[2]) + ") "
+ " vel = (" + std::to_string(v[0])
+ ", " + std::to_string(v[1])
+ ", " + std::to_string(v[2]) + ")";
// Show every 1000 updates in standard
if (++displayCpt > 1000)
{
std::cout << "\r-- " << module->getName() << message << std::flush;
displayCpt = 0;
}
// Asynchronous log
if (logger->readyForLoggingWithFrequency())
{
logger->log(message, true);
logger->updateLogTime();
}
};
auto postCleanUpFoo = [&logger](Module* module)
{
logger->shutdown();
delete logger;
};
falcon0->setPostInitCallback(postInitFoo);
falcon0->setPostUpdateCallback(postUpdateFoo);
//falcon1->setPostUpdateCallback(postUpdateFoo);
falcon0->setPostCleanUpCallback(postCleanUpFoo);
// falcon1->setPostInitCallback(postInitFoo);
// falcon1->setPostUpdateCallback(postUpdateFoo);
// falcon1->setPostCleanUpCallback(postCleanUpFoo);
// Run
sdk->setCurrentScene(scene);
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment