Skip to content

Commit

Permalink
wip: feat: add IRLoggerToSpd class
Browse files Browse the repository at this point in the history
Add the `IRLoggerToSpd` class, that converts from
[IRImagerDirect SDK's IRLogger logs][1], to spdlogs.

Since IRLogger only supports using a file for output, we're using
[uvw][] to automatically listen on the file and pipe the output to
spdlog.

[1]: http://documentation.evocortex.com/libirimager2/html/classevo_1_1IRLogger.html
[uvw]: https://github.com/skypjack/uvw

**WIP**:
  - Reading from the log fix currently works, but only when using
    uvw's file API, not the pipe API. This causes 100% CPU usage, which
    isn't great.
  - Still needs to handle log parsing
  - Still need to connect up fully to IRLogger
  • Loading branch information
aloisklink committed Sep 11, 2023
1 parent 75e055b commit 65f5046
Show file tree
Hide file tree
Showing 4 changed files with 247 additions and 2 deletions.
19 changes: 19 additions & 0 deletions CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -108,6 +108,23 @@ else()
target_link_libraries(irimager_class PRIVATE IRImager::IRImager)
endif(IRImager_mock)

add_library(irlogger_to_spd OBJECT
"src/nqm/irimager/irlogger_to_spd.cpp"
)
set_target_properties(irlogger_to_spd PROPERTIES
PRIVATE_HEADER
"src/nqm/irimager/irlogger_to_spd.hpp"
POSITION_INDEPENDENT_CODE ON # -fPIC
)
target_link_libraries(irlogger_to_spd
PUBLIC
propagate_const::propagate_const
PRIVATE
spdlog::spdlog_header_only
uvw::uvw
uv_a # static version, since we need very new v1.46.0 features
)

add_library(logger OBJECT
"src/nqm/irimager/logger.cpp"
)
Expand All @@ -121,6 +138,7 @@ target_link_libraries(logger
pybind11::pybind11
PRIVATE
spdlog::spdlog_header_only
irlogger_to_spd
)

pybind11_add_module(irimager MODULE
Expand All @@ -135,6 +153,7 @@ target_link_libraries(irimager
PRIVATE
pybind11::headers
irimager_class
irlogger_to_spd
logger
)

Expand Down
181 changes: 181 additions & 0 deletions src/nqm/irimager/irlogger_to_spd.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,181 @@
#include "./irlogger_to_spd.hpp"

#include <spdlog/spdlog.h>

#include <atomic>
#include <exception>
#include <future>
#include <memory>
#include <uvw.hpp>

class IRLoggerToSpd::impl {
public:
impl(const std::filesystem::path &socket_path) { start_thread(socket_path); }

virtual ~impl() {
try {
stop_thread();
} catch (std::exception &e) {
spdlog::error("IRLoggerToSpd thread crashed: {}", e.what());
}
}

private:
void start_thread(const std::filesystem::path &socket_path) {
spdlog::debug("starting thread");

logger_thread = std::async(
std::launch::async,
[this,
socket_path // capture by value, since this will run in another thread
] {
spdlog::debug("started in new thread");

auto loop = uvw::loop::get_default();

// TODO: do we need to check for nullptr?
this->message = loop->resource<uvw::async_handle>();

spdlog::debug("checking for early stop");

if (this->stop) { // in case calling thread stopped this before
// `message` was created
spdlog::info("early exit!");
loop->stop();
}

this->message->on<uvw::async_event>(
[this, &loop](const uvw::async_event &, uvw::async_handle &) {
if (this->stop) {
loop->stop();
}
});

spdlog::debug("message handler added");

#ifdef FIFO_STREAMING_WORKKING
auto log_file_reader = loop->resource<uvw::pipe_handle>();

log_file_reader->on<uvw::connect_event>(
[](const uvw::connect_event &, uvw::pipe_handle &pipe_handle) {
spdlog::debug("Connection");
pipe_handle.on<uvw::end_event>(
[](const uvw::end_event &, uvw::pipe_handle &srv) {
srv.close();
});
pipe_handle.on<uvw::data_event>(
[](const uvw::data_event &data, uvw::pipe_handle &) {
auto string_data =
std::string_view(data.data.get(), data.length);

// TODO PARSE LOGS
spdlog::info(string_data);
});
pipe_handle.read();
});

log_file_reader->on<uvw::error_event>(
[&loop](const uvw::error_event &error, uvw::pipe_handle &) {
spdlog::error("log_file_reader error {}", error.what());
});

spdlog::debug("Connecting to socket {}", socket_path.string());
log_file_reader->connect(socket_path.string());
log_file_reader->read();
#endif

#define UVW_FILE_STREAMING 1
#ifdef UVW_FILE_STREAMING
/**
* This currently works, but it's very inefficient, since it maxes
* out the CPU to 100%!
*/
auto log_file_reader = loop->resource<uvw::file_req>();

size_t file_offset = 0;
log_file_reader->on<uvw::fs_event>([&](const auto &event, auto &req) {
switch (event.type) {
case uvw::fs_req::fs_type::READ: {
if (event.result != 0) {
auto string_data =
std::string_view(event.read.data.get(), event.result);
file_offset += event.result;

// TODO: PARSE LOGS somehow?
spdlog::info(string_data);
}

[[fallthrough]];
}
case uvw::fs_req::fs_type::OPEN:
req.read(static_cast<int64_t>(file_offset), 16);
break;
default:
spdlog::error(
"Unexpected fs_req type {}",
static_cast<std::underlying_type_t<uvw::fs_req::fs_type>>(
event.type));
[[fallthrough]];
case uvw::fs_req::fs_type::CLOSE:
spdlog::debug("Closing file {}", socket_path.string());
log_file_reader->close();
}
});

spdlog::debug("Reading from file at {}", socket_path.string());
log_file_reader->open(socket_path.string(),
uvw::file_req::file_open_flags::RDONLY, 0644);
#endif // POSIX hack

spdlog::debug("running loop in another thread");
loop->run();
});
}

void stop_thread() {
stop = true;
if (message != nullptr) {
message->send();
}

logger_thread.get();
}

std::shared_future<void> logger_thread;

/** Send messages to libuv thread from here */
std::shared_ptr<uvw::async_handle> message;
/** If `true`, stop the logger thread when a @p message is received */
std::atomic<bool> stop = false;
};

/**
* @see IRLoggerToSpd::IRLoggerToSpd() documentation.
*/
static std::filesystem::path default_socket_path() {
const char *xdg_runtime_dir_ptr = std::getenv("XDG_RUNTIME_DIR");
if (xdg_runtime_dir_ptr) {
auto xdg_runtime_dir =
std::filesystem::path(xdg_runtime_dir_ptr) / "nqm-irimager";
try {
std::filesystem::create_directory(xdg_runtime_dir);
return xdg_runtime_dir / "irlogger.fifo";
} catch (const std::filesystem::filesystem_error &e) {
// on no_such_file_or_directory error, just use temp_directory_path()
if (e.code() != std::errc::no_such_file_or_directory) {
throw e;
}
}
}

auto temp_dir = std::filesystem::temp_directory_path() / "nqm-irimager";
std::filesystem::create_directory(temp_dir);
return temp_dir / "irlogger.fifo";
}

IRLoggerToSpd::IRLoggerToSpd() : IRLoggerToSpd(default_socket_path()) {}

IRLoggerToSpd::IRLoggerToSpd(const std::filesystem::path &socket_path)
: pImpl{std::make_unique<IRLoggerToSpd::impl>(socket_path)} {}

IRLoggerToSpd::~IRLoggerToSpd() {}
30 changes: 30 additions & 0 deletions src/nqm/irimager/irlogger_to_spd.hpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,30 @@
#include <filesystem>
#include <memory>

#include "propagate_const.h"

class IRLoggerToSpd {
public:
/**
* Creates an IRLoggerToSpd using a random named socket.
*
* - The socket is placed into `$XDG_RUNTIME_DIR/nqm-irimager/` if it exists.
* - Otherwise, an `{std::filesystem::temp_directory_path()}/nqm-irimager/`
* is used.
*/
IRLoggerToSpd();
/**
* Creates an IRLoggerToSpd using a socket on the given path.
*/
IRLoggerToSpd(const std::filesystem::path &socket_path);

virtual ~IRLoggerToSpd();

/** pImpl implementation */
struct impl;

private:
// pImpl, see https://en.cppreference.com/w/cpp/language/pimpl
std::experimental::fundamentals_v2::propagate_const<std::unique_ptr<impl>>
pImpl;
};
19 changes: 17 additions & 2 deletions src/nqm/irimager/logger.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,9 @@
#include <spdlog/spdlog.h>

#include <atomic>
#include <iostream>

#include "./irlogger_to_spd.hpp"

/** Map spdlog's spd::level::level_enum enum to our LogLevel enum */
inline LogLevel spd_level_to_irimager_level(spdlog::level::level_enum input) {
Expand Down Expand Up @@ -38,14 +41,26 @@ struct Logger::impl {
*
* @param logging_callback The function to call with log data.
*/
impl(LoggingCallback logging_callback) { redirect_spd(logging_callback); }
impl(LoggingCallback logging_callback) {
redirect_spd(logging_callback);

// construct after calling redirect_spd, so we can see logs during
// construction
ir_logger_to_spd = std::make_unique<IRLoggerToSpd>();
}

virtual ~impl() { reset_spd_redirect(); }
virtual ~impl() {
ir_logger_to_spd = nullptr;
reset_spd_redirect();
}

private:
/** If we've called redirect_spd(), this var stores the original logger */
std::shared_ptr<spdlog::logger> old_logger;

/** Handles piping IRImageSDK logs to spdlog */
std::unique_ptr<IRLoggerToSpd> ir_logger_to_spd;

/** Redirects calls to `spdlog::log()` in C++ to the given callback */
void redirect_spd(LoggingCallback logging_callback) {
reset_spd_redirect();
Expand Down

0 comments on commit 65f5046

Please sign in to comment.