From 5a0017a8fed1f90e137c5010b3a1b0255ccc54ca Mon Sep 17 00:00:00 2001 From: meeh Date: Sun, 30 Sep 2018 09:30:39 +0000 Subject: [PATCH] Mac OSX Launcher: Adding a logger library I wrote a good while ago, refactored it to work with the launcher. --- launchers/macosx/Logger.h | 263 +++++++++++++++++++++ launchers/macosx/Logger.mm | 370 ++++++++++++++++++++++++++++++ launchers/macosx/LoggerWorker.cpp | 320 ++++++++++++++++++++++++++ launchers/macosx/LoggerWorker.hpp | 143 ++++++++++++ 4 files changed, 1096 insertions(+) create mode 100644 launchers/macosx/Logger.h create mode 100644 launchers/macosx/Logger.mm create mode 100644 launchers/macosx/LoggerWorker.cpp create mode 100644 launchers/macosx/LoggerWorker.hpp diff --git a/launchers/macosx/Logger.h b/launchers/macosx/Logger.h new file mode 100644 index 000000000..e67732a00 --- /dev/null +++ b/launchers/macosx/Logger.h @@ -0,0 +1,263 @@ +// +// Logger.h +// I2PLauncher +// +// Created by Mikal Villa on 27/09/2018. +// Copyright © 2018 The I2P Project. All rights reserved. +// Imported/Refactored from earlier C++ project of Meeh +// + +#ifndef Logger_h +#define Logger_h + +#ifdef __cplusplus + +#include +#include +#include +#include +#include +#include +#include + + +/** + * For details please see this + * REFERENCE: http://www.cppreference.com/wiki/io/c/printf_format + * \verbatim + * + There are different %-codes for different variable types, as well as options to + limit the length of the variables and whatnot. + Code Format + %[flags][width][.precision][length]specifier + SPECIFIERS + ---------- + %c character + %d signed integers + %i signed integers + %e scientific notation, with a lowercase “e” + %E scientific notation, with a uppercase “E” + %f floating point + %g use %e or %f, whichever is shorter + %G use %E or %f, whichever is shorter + %o octal + %s a string of characters + %u unsigned integer + %x unsigned hexadecimal, with lowercase letters + %X unsigned hexadecimal, with uppercase letters + %p a pointer + %n the argument shall be a pointer to an integer into which is placed the number of characters written so far + + */ + +/* + Usage: + + SharedLogWorker logger(argv[0], path_to_log_file); + MeehLog::initializeLogging(&logger); + + MLOG(INFO) << "Test SLOG INFO"; + MLOG(DEBUG) << "Test SLOG DEBUG"; + + */ + + +class SharedLogWorker; + +#if !(defined(__PRETTY_FUNCTION__)) +#define __PRETTY_FUNCTION__ __FUNCTION__ +#endif + +const int ML_ANNOYING = 0; +const int ML_DEBUG = 1; +const int ML_INFO = 2; +const int ML_WARN = 3; +const int ML_ERROR = 4; +const int ML_FATAL = 5; +static const std::string kFatalLogExpression = ""; + +#define MLOG_ANNOYING MeehLog::internal::LogMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,"ML_ANNOYING") +#define MLOG_DEBUG MeehLog::internal::LogMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,"ML_DEBUG") +#define MLOG_INFO MeehLog::internal::LogMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,"ML_INFO") +#define MLOG_WARN MeehLog::internal::LogMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,"ML_WARN") +#define MLOG_ERROR MeehLog::internal::LogMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,"ML_ERROR") +#define MLOG_FATAL MeehLog::internal::LogContractMessage(__FILE__,__LINE__,__PRETTY_FUNCTION__,k_fatal_log_expression) + +// MLOG(level) is the API for the stream log +#define MLOG(level) MLOG_##level.messageStream() + +// conditional stream log +#define LOG_IF(level, boolean_expression) \ + if(true == boolean_expression) \ + MLOG_##level.messageStream() + +#define MASSERT(boolean_expression) \ + if (false == (boolean_expression)) \ + MeehLog::internal::LogContractMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__, #boolean_expression).messageStream() + + +#define MLOGF_ANNOYING MeehLog::internal::LogMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,"ML_ANNOYING") +#define MLOGF_INFO MeehLog::internal::LogMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,"ML_INFO") +#define MLOGF_DEBUG MeehLog::internal::LogMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,"ML_DEBUG") +#define MLOGF_WARN MeehLog::internal::LogMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,"ML_WARN") +#define MLOGF_ERROR MeehLog::internal::LogMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,"ML_ERROR") +#define MLOGF_FATAL MeehLog::internal::LogContractMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,k_fatal_log_expression) + +// MLOGF(level,msg,...) is the API for the "printf" like log +#define MLOGF(level, printf_like_message, ...) \ + MLOGF_##level.messageSave(printf_like_message, ##__VA_ARGS__) + +// conditional log printf syntax +#define MLOGF_IF(level,boolean_expression, printf_like_message, ...) \ + if(true == boolean_expression) \ + MLOG_##level.messageSave(printf_like_message, ##__VA_ARGS__) + +// Design By Contract, printf-like API syntax with variadic input parameters. Throws std::runtime_eror if contract breaks */ +#define MASSERTF(boolean_expression, printf_like_message, ...) \ + if (false == (boolean_expression)) \ + MeehLog::internal::LogContractMessage(__FILE__, __LINE__, __PRETTY_FUNCTION__,#boolean_expression).messageSave(printf_like_message, ##__VA_ARGS__) + +namespace MeehLog { + + + // PUBLIC API: + /** Install signal handler that catches FATAL C-runtime or OS signals + SIGABRT ABORT (ANSI), abnormal termination + SIGFPE Floating point exception (ANSI): http://en.wikipedia.org/wiki/SIGFPE + SIGILL ILlegal instruction (ANSI) + SIGSEGV Segmentation violation i.e. illegal memory reference + SIGTERM TERMINATION (ANSI) */ + void installSignalHandler(); + + namespace internal { + + + /** \return signal_name. Ref: signum.h and \ref installSignalHandler */ + std::string signalName(int signal_number); + + /** Re-"throw" a fatal signal, previously caught. This will exit the application + * This is an internal only function. Do not use it elsewhere. It is triggered + * from g2log, g2LogWorker after flushing messages to file */ + void exitWithDefaultSignalHandler(int signal_number); + + std::time_t systemtime_now(); + bool isLoggingInitialized(); + + struct LogEntry { + LogEntry(std::string msg, std::time_t timestamp) : mMsg(msg), mTimestamp(timestamp) {} + LogEntry(const LogEntry& other): mMsg(other.mMsg), mTimestamp(other.mTimestamp) {} + LogEntry& operator=(const LogEntry& other) { + mMsg = other.mMsg; + mTimestamp = other.mTimestamp; + return *this; + } + + + std::string mMsg; + std::time_t mTimestamp; + }; + + /** Trigger for flushing the message queue and exiting the application + A thread that causes a FatalMessage will sleep forever until the + application has exited (after message flush) */ + struct FatalMessage { + enum FatalType {kReasonFatal, kReasonOS_FATAL_SIGNAL}; + FatalMessage(LogEntry message, FatalType type, int signal_id); + ~FatalMessage() {}; + FatalMessage& operator=(const FatalMessage& fatal_message); + + + LogEntry mMessage; + FatalType mType; + int mSignalId; + }; + // Will trigger a FatalMessage sending + struct FatalTrigger { + FatalTrigger(const FatalMessage& message); + ~FatalTrigger(); + FatalMessage mMessage; + }; + + // Log message for 'printf-like' or stream logging, it's a temporary message constructions + class LogMessage { + public: + LogMessage(const std::string& file, const int line, const std::string& function, const std::string& level); + virtual ~LogMessage(); // at destruction will flush the message + + std::ostringstream& messageStream() {return mStream;} + + // To generate warn on illegal printf format + #ifndef __GNUC__ + #define __attribute__(x) + #endif + // C++ get 'this' as first arg + void messageSave(const char* printf_like_message, ...) + __attribute__((format(printf, 2, 3) )); + + protected: + const std::string mFile; + const int mLine; + const std::string mFunction; + const std::string mLevel; + std::ostringstream mStream; + std::string mLogEntry; + std::time_t mTimestamp; + }; + + // 'Design-by-Contract' temporary messsage construction + class LogContractMessage : public LogMessage { + public: + LogContractMessage(const std::string& file, const int line, + const std::string& function, const std::string& boolean_expression); + virtual ~LogContractMessage(); // at destruction will flush the message + + protected: + const std::string mExpression; + }; + + // wrap for std::chrono::system_clock::now() + std::time_t systemtime_now(); + + } // namespace internal + + + + /** Should be called at very first startup of the software with \ref SharedLogWorker pointer. + * Ownership of the \ref SharedLogWorker is the responsibilkity of the caller */ + void initializeLogging(SharedLogWorker* logger); + + /** Shutdown the logging by making the pointer to the background logger to nullptr + * The \ref pointer to the SharedLogWorker is owned by the instantniater \ref initializeLogging + * and is not deleted. + */ + void shutDownLogging(); + + /** Same as the Shutdown above but called by the destructor of the LogWorker, thus ensuring that no further + * LOG(...) calls can happen to a non-existing LogWorker. + * @param active MUST BE the LogWorker initialized for logging. If it is not then this call is just ignored + * and the logging continues to be active. + * @return true if the correct worker was given,. and shutDownLogging was called + */ + bool shutDownLoggingForActiveOnly(SharedLogWorker* active); + + + typedef std::chrono::steady_clock::time_point steady_time_point; + typedef std::chrono::time_point system_time_point; + typedef std::chrono::milliseconds milliseconds; + typedef std::chrono::microseconds microseconds; + + /** return time representing POD struct (ref ctime + wchar) that is normally + * retrieved with std::localtime. MeehLog::localtime is threadsafe which std::localtime is not. + * MeehLog::localtime is probably used together with @ref MeehLog::systemtime_now */ + tm localtime(const std::time_t& time); + + /** format string must conform to std::put_time's demands. + * WARNING: At time of writing there is only so-so compiler support for + * std::put_time. A possible fix if your c++11 library is not updated is to + * modify this to use std::strftime instead */ + std::string localtime_formatted(const std::time_t& time_snapshot, const std::string& time_format) ; +} // namespace MeehLog + +#endif // __cplusplus + +#endif /* Logger_h */ diff --git a/launchers/macosx/Logger.mm b/launchers/macosx/Logger.mm new file mode 100644 index 000000000..2c303cd9b --- /dev/null +++ b/launchers/macosx/Logger.mm @@ -0,0 +1,370 @@ +// +// Logger.cpp +// I2PLauncher +// +// Created by Mikal Villa on 27/09/2018. +// Copyright © 2018 The I2P Project. All rights reserved. +// Imported/Refactored from earlier C++ project of Meeh +// + +#include +#include +#include +#include // exceptions +#include // vsnprintf +#include +#include +#include +#include + +#include +#include +#include +#include +#include + +#include "Logger.h" +#include "LoggerWorker.hpp" + +namespace { + std::once_flag gIsInitialized; + std::once_flag gSetFirstUninitializedFlag; + std::once_flag gSaveFirstUnintializedFlag; + SharedLogWorker* gLoggerWorkerInstance = nullptr; + MeehLog::internal::LogEntry gFirstUnintializedMsg = {"", 0}; + std::mutex gLoggerMasterMutex; + const std::string kTruncatedWarningText = "[...truncated...]"; + + std::string splitFileName(const std::string& str) { + size_t found; + found = str.find_last_of("\\"); + return str.substr(found + 1); + } + + void saveToLogger(const MeehLog::internal::LogEntry& logEntry) { + // Uninitialized messages are ignored but does not MASSERT/crash the logger + if (!MeehLog::internal::isLoggingInitialized()) { + std::string err("LOGGER NOT INITIALIZED: " + logEntry.mMsg); + std::call_once(gSetFirstUninitializedFlag, + [&] { gFirstUnintializedMsg.mMsg += err; + gFirstUnintializedMsg.mTimestamp = MeehLog::internal::systemtime_now(); + }); + // dump to std::err all the non-initialized logs + std::cerr << err << std::endl; + return; + } + // Save the first uninitialized message, if any + std::call_once(gSaveFirstUnintializedFlag, [] { + if (!gFirstUnintializedMsg.mMsg.empty()) { + gLoggerWorkerInstance->save(gFirstUnintializedMsg); + } + }); + + gLoggerWorkerInstance->save(logEntry); + } + void crashHandler(int signal_number, siginfo_t* info, void* unused_context) { + const size_t max_dump_size = 50; + void* dump[max_dump_size]; + size_t size = backtrace(dump, max_dump_size); + char** messages = backtrace_symbols(dump, (int)size); // overwrite sigaction with caller's address + + std::ostringstream oss; + oss << "Received fatal signal: " << MeehLog::internal::signalName(signal_number); + oss << "(" << signal_number << ")" << std::endl; + oss << "PID: " << getpid() << std::endl; + + // dump stack: skip first frame, since that is here + for (size_t idx = 1; idx < size && messages != nullptr; ++idx) { + char* mangled_name = 0, *offset_begin = 0, *offset_end = 0; + // find parantheses and +address offset surrounding mangled name + for (char* p = messages[idx]; *p; ++p) { + if (*p == '(') { + mangled_name = p; + } else if (*p == '+') { + offset_begin = p; + } else if (*p == ')') { + offset_end = p; + break; + } + } + + // if the line could be processed, attempt to demangle the symbol + if (mangled_name && offset_begin && offset_end && + mangled_name < offset_begin) { + *mangled_name++ = '\0'; + *offset_begin++ = '\0'; + *offset_end++ = '\0'; + + int status; + char* real_name = abi::__cxa_demangle(mangled_name, 0, 0, &status); + // if demangling is successful, output the demangled function name + if (status == 0) { + oss << "stack dump [" << idx << "] " << messages[idx] << " : " << real_name << "+"; + oss << offset_begin << offset_end << std::endl; + } + // otherwise, output the mangled function name + else { + oss << "stack dump [" << idx << "] " << messages[idx] << mangled_name << "+"; + oss << offset_begin << offset_end << std::endl; + } + free(real_name); // mallocated by abi::__cxa_demangle(...) + } else { + // no demangling done -- just dump the whole line + oss << "stack dump [" << idx << "] " << messages[idx] << std::endl; + } + } // END: for(size_t idx = 1; idx < size && messages != nullptr; ++idx) + + + + free(messages); + { + // Local scope, trigger send + using namespace MeehLog::internal; + std::ostringstream fatal_stream; + fatal_stream << "\n\n***** FATAL TRIGGER RECEIVED ******* " << std::endl; + fatal_stream << oss.str() << std::endl; + fatal_stream << "\n***** RETHROWING SIGNAL " << signalName(signal_number) << "(" << signal_number << ")" << std::endl; + + LogEntry entry = {fatal_stream.str(), systemtime_now()}; + FatalMessage fatal_message(entry, FatalMessage::kReasonOS_FATAL_SIGNAL, signal_number); + FatalTrigger trigger(fatal_message); std::ostringstream oss; + std::cerr << fatal_message.mMessage.mMsg << std::endl << std::flush; + } // message sent to SharedLogWorker + // wait to die -- will be inside the FatalTrigger + } +} // End anonymous namespace + + + +namespace MeehLog { + + // signalhandler and internal clock is only needed to install once + // for unit testing purposes the initializeLogging might be called + // several times... for all other practical use, it shouldn't! + void initializeLogging(SharedLogWorker* bgworker) { + std::call_once(gIsInitialized, []() { + //installSignalHandler(); + }); + + std::lock_guard lock(gLoggerMasterMutex); + MASSERT(!internal::isLoggingInitialized()); + MASSERT(bgworker != nullptr); + gLoggerWorkerInstance = bgworker; + } + + + + void shutDownLogging() { + std::lock_guard lock(gLoggerMasterMutex); + gLoggerWorkerInstance = nullptr; + } + + + + bool shutDownLoggingForActiveOnly(SharedLogWorker* active) { + if (internal::isLoggingInitialized() && nullptr != active && + (dynamic_cast(active) != dynamic_cast(gLoggerWorkerInstance))) { + MLOG(WARN) << "\nShutting down logging, but the ID of the Logger is not the one that is active." + << "\nHaving multiple instances of the MeehLog::LogWorker is likely a BUG" + << "\nEither way, this call to shutDownLogging was ignored"; + return false; + } + shutDownLogging(); + return true; + } + + void installSignalHandler() { + struct sigaction action; + memset(&action, 0, sizeof(action)); + sigemptyset(&action.sa_mask); + action.sa_sigaction = &crashHandler; // callback to crashHandler for fatal signals + // sigaction to use sa_sigaction file. ref: http://www.linuxprogrammingblog.com/code-examples/sigaction + action.sa_flags = SA_SIGINFO; + + // do it verbose style - install all signal actions + if (sigaction(SIGABRT, &action, NULL) < 0) + perror("sigaction - SIGABRT"); + if (sigaction(SIGFPE, &action, NULL) < 0) + perror("sigaction - SIGFPE"); + if (sigaction(SIGILL, &action, NULL) < 0) + perror("sigaction - SIGILL"); + if (sigaction(SIGSEGV, &action, NULL) < 0) + perror("sigaction - SIGSEGV"); + if (sigaction(SIGTERM, &action, NULL) < 0) + perror("sigaction - SIGTERM"); + } + + namespace internal { + + std::time_t systemtime_now() + { + system_time_point system_now = std::chrono::system_clock::now(); + return std::chrono::system_clock::to_time_t(system_now); + } + + bool isLoggingInitialized() { + return gLoggerWorkerInstance != nullptr; + } + + LogContractMessage::LogContractMessage(const std::string& file, const int line, + const std::string& function, const std::string& boolean_expression) + : LogMessage(file, line, function, "FATAL") + , mExpression(boolean_expression) + {} + + LogContractMessage::~LogContractMessage() { + std::ostringstream oss; + if (0 == mExpression.compare(kFatalLogExpression)) { + oss << "\n[ *******\tEXIT trigger caused by MLOG(FATAL): \n"; + } else { + oss << "\n[ *******\tEXIT trigger caused by broken Contract: MASSERT(" << mExpression << ")\n"; + } + mLogEntry = oss.str(); + } + + LogMessage::LogMessage(const std::string& file, const int line, const std::string& function, const std::string& level) + : mFile(file) + , mLine(line) + , mFunction(function) + , mLevel(level) + , mTimestamp(systemtime_now()) + {} + + LogMessage::~LogMessage() { + using namespace internal; + std::ostringstream oss; + const bool fatal = (0 == mLevel.compare("FATAL")); + oss << mLevel << " [" << splitFileName(mFile); + if (fatal) + oss << " at function: " << mFunction ; + oss << " Line: " << mLine << "]"; + + const std::string str(mStream.str()); + if (!str.empty()) { + oss << '"' << str << '"'; + } + mLogEntry += oss.str(); + + + if (fatal) { // os_fatal is handled by crashhandlers + { + // local scope - to trigger FatalMessage sending + FatalMessage::FatalType fatal_type(FatalMessage::kReasonFatal); + FatalMessage fatal_message({mLogEntry, mTimestamp}, fatal_type, SIGABRT); + FatalTrigger trigger(fatal_message); + std::cerr << mLogEntry << "\t******* ]" << std::endl << std::flush; + } // will send to worker + } + + saveToLogger({mLogEntry, mTimestamp}); // message saved + } + + // represents the actual fatal message + FatalMessage::FatalMessage(LogEntry message, FatalType type, int signal_id) + : mMessage(message) + , mType(type) + , mSignalId(signal_id) {} + + + FatalMessage& FatalMessage::operator=(const FatalMessage& other) { + mMessage = other.mMessage; + mType = other.mType; + mSignalId = other.mSignalId; + return *this; + } + + std::string signalName(int signal_number) { + switch (signal_number) { + case SIGABRT: return "SIGABRT"; break; + case SIGFPE: return "SIGFPE"; break; + case SIGSEGV: return "SIGSEGV"; break; + case SIGILL: return "SIGILL"; break; + case SIGTERM: return "SIGTERM"; break; + default: + std::ostringstream oss; + oss << "UNKNOWN SIGNAL(" << signal_number << ")"; + return oss.str(); + } + } + + void exitWithDefaultSignalHandler(int signal_number) { + std::cerr << "Exiting - FATAL SIGNAL: " << signal_number << " " << std::flush; + struct sigaction action; + memset(&action, 0, sizeof(action)); // + sigemptyset(&action.sa_mask); + action.sa_handler = SIG_DFL; // take default action for the signal + sigaction(signal_number, &action, NULL); + kill(getpid(), signal_number); + abort(); // should never reach this + } + + /** Fatal call saved to logger. This will trigger SIGABRT or other fatal signal + * to exit the program. After saving the fatal message the calling thread + * will sleep forever (i.e. until the background thread catches up, saves the fatal + * message and kills the software with the fatal signal. + */ + void fatalCallToLogger(FatalMessage message) { + if (!isLoggingInitialized()) { + std::ostringstream error; + error << "FATAL CALL but logger is NOT initialized\n" + << "SIGNAL: " << MeehLog::internal::signalName(message.mSignalId) + << "\nMessage: \n" << message.mMessage.mMsg << std::flush; + std::cerr << error.str(); + + //internal::exitWithDefaultSignalHandler(message.mSignalId); + } + gLoggerWorkerInstance->fatal(message); + while (true) { + std::this_thread::sleep_for(std::chrono::seconds(1)); + } + } + + std::function gFatalToMLogWorkerFunctionPtr = fatalCallToLogger; + + // used to RAII trigger fatal message sending to g2LogWorker + FatalTrigger::FatalTrigger(const FatalMessage& message) + : mMessage(message) {} + + // at destruction, flushes fatal message to g2LogWorker + FatalTrigger::~FatalTrigger() { + // either we will stay here eternally, or it's in unit-test mode + gFatalToMLogWorkerFunctionPtr(mMessage); + } + + // This mimics the original "std::put_time(const std::tm* tmb, const charT* fmt)" + // This is needed since latest version (at time of writing) of gcc4.7 does not implement this library function yet. + // return value is SIMPLIFIED to only return a std::string + std::string put_time(const struct tm* tmb, const char* c_time_format) + { + const size_t size = 1024; + char buffer[size]; // IMPORTANT: check now and then for when gcc will implement std::put_time finns. + // ... also ... This is way more buffer space then we need + auto success = std::strftime(buffer, size, c_time_format, tmb); + if (0 == success) + return c_time_format; // For this hack it is OK but in case of more permanent we really should throw here, or even assert + return buffer; + } + + } // ns internal + + + tm localtime(const std::time_t& time) + { + struct tm tm_snapshot; + localtime_r(&time, &tm_snapshot); // POSIX + return tm_snapshot; + } + + /// returns a std::string with content of time_t as localtime formatted by input format string + /// * format string must conform to std::put_time + /// This is similar to std::put_time(std::localtime(std::time_t*), time_format.c_str()); + std::string localtime_formatted(const std::time_t& time_snapshot, const std::string& time_format) + { + std::tm t = localtime(time_snapshot); // could be const, but cannot due to VS2012 is non conformant for C++11's std::put_time (see above) + std::stringstream buffer; + buffer << MeehLog::internal::put_time(&t, time_format.c_str()); // format example: //"%Y/%m/%d %H:%M:%S"); + return buffer.str(); + } + +} // ns MeehLog + diff --git a/launchers/macosx/LoggerWorker.cpp b/launchers/macosx/LoggerWorker.cpp new file mode 100644 index 000000000..0d5ce37c7 --- /dev/null +++ b/launchers/macosx/LoggerWorker.cpp @@ -0,0 +1,320 @@ +// +// LoggerWorker.cpp +// I2PLauncher +// +// Created by Mikal Villa on 27/09/2018. +// Copyright © 2018 The I2P Project. All rights reserved. +// Imported/Refactored from earlier C++ project of Meeh +// + +#include "LoggerWorker.hpp" +#include "Logger.h" + +#include +#include +#include +#include +#include +#include +#include +#include + +using namespace MeehLog; +using namespace MeehLog::internal; + +Active::Active(): mDone(false){} + +Active::~Active() { + Callback quit_token = std::bind(&Active::doDone, this); + send(quit_token); // tell thread to exit + mThd.join(); +} + +// Add asynchronously a work-message to queue +void Active::send(Callback msg_){ + mMq.push(msg_); +} + + +// Will wait for msgs if queue is empty +// A great explanation of how this is done (using Qt's library): +// http://doc.qt.nokia.com/stable/qwaitcondition.html +void Active::run() { + while (!mDone) { + // wait till job is available, then retrieve it and + // executes the retrieved job in this thread (background) + Callback func; + mMq.wait_and_pop(func); + func(); + } +} + +// Factory: safe construction of object before thread start +std::unique_ptr Active::createActive(){ + std::unique_ptr aPtr(new Active()); + aPtr->mThd = std::thread(&Active::run, aPtr.get()); + return aPtr; +} + +namespace { + static const std::string date_formatted = "%Y/%m/%d"; + static const std::string time_formatted = "%H:%M:%S"; + static const std::string file_name_time_formatted = "%Y%m%d-%H%M%S"; + + // check for filename validity - filename should not be part of PATH + bool isValidFilename(const std::string prefix_filename) { + + std::string illegal_characters("/,|<>:#$%{}()[]\'\"^!?+* "); + size_t pos = prefix_filename.find_first_of(illegal_characters, 0); + if (pos != std::string::npos) { + std::cerr << "Illegal character [" << prefix_filename.at(pos) << "] in logname prefix: " << "[" << prefix_filename << "]" << std::endl; + return false; + } else if (prefix_filename.empty()) { + std::cerr << "Empty filename prefix is not allowed" << std::endl; + return false; + } + + return true; + } + + // Clean up the path if put in by mistake in the prefix + std::string prefixSanityFix(std::string prefix) { + prefix.erase(std::remove_if(prefix.begin(), prefix.end(), ::isspace), prefix.end()); + prefix.erase(std::remove( prefix.begin(), prefix.end(), '\\'), prefix.end()); // '\\' + prefix.erase(std::remove( prefix.begin(), prefix.end(), '.'), prefix.end()); // '.' + prefix.erase(std::remove(prefix.begin(), prefix.end(), ':'), prefix.end()); // ':' + + if (!isValidFilename(prefix)) { + return ""; + } + return prefix; + } + std::string pathSanityFix(std::string path, std::string file_name) { + // Unify the delimeters,. maybe sketchy solution but it seems to work + // on at least win7 + ubuntu. All bets are off for older windows + std::replace(path.begin(), path.end(), '\\', '/'); + + // clean up in case of multiples + auto contains_end = [&](std::string & in) -> bool { + size_t size = in.size(); + if (!size) return false; + char end = in[size - 1]; + return (end == '/' || end == ' '); + }; + + while (contains_end(path)) { path.erase(path.size() - 1); } + if (!path.empty()) { + path.insert(path.end(), '/'); + } + path.insert(path.size(), file_name); + return path; + } + + + std::string createLogFileName(const std::string& verified_prefix) { + std::stringstream ossName; + ossName.fill('0'); + ossName << verified_prefix << MeehLog::localtime_formatted(systemtime_now(), file_name_time_formatted); + ossName << ".log"; + return ossName.str(); + } + + + bool openLogFile(const std::string& complete_file_with_path, std::ofstream& outstream) { + std::ios_base::openmode mode = std::ios_base::out; // for clarity: it's really overkill since it's an ofstream + mode |= std::ios_base::trunc; + outstream.open(complete_file_with_path, mode); + if (!outstream.is_open()) { + std::ostringstream ss_error; + ss_error << "FILE ERROR: could not open log file:[" << complete_file_with_path << "]"; + ss_error << "\nstd::ios_base state = " << outstream.rdstate(); + std::cerr << ss_error.str().c_str() << std::endl << std::flush; + outstream.close(); + return false; + } + std::ostringstream ss_entry; + // Day Month Date Time Year: is written as "%a %b %d %H:%M:%S %Y" and formatted output as : Wed Aug 10 08:19:45 2014 + ss_entry << "MeehLog created log file at: " << MeehLog::localtime_formatted(systemtime_now(), "%a %b %d %H:%M:%S %Y") << "\n"; + ss_entry << "LOG format: [YYYY/MM/DD hh:mm:ss uuu* LEVEL FILE:LINE] message (uuu*: microsecond counter since initialization of log worker)\n\n"; + outstream << ss_entry.str() << std::flush; + outstream.fill('0'); + return true; + } + + + std::unique_ptr createLogFile(const std::string& file_with_full_path) { + std::unique_ptr out(new std::ofstream); + std::ofstream& stream(*(out.get())); + bool success_with_open_file = openLogFile(file_with_full_path, stream); + if (false == success_with_open_file) { + out.release(); // nullptr contained ptr signals error in creating the log file + } + return out; + } +} // end anonymous namespace + +/** The Real McCoy Background worker, while g2LogWorker gives the + * asynchronous API to put job in the background the g2LogWorkerImpl + * does the actual background thread work */ +struct SharedLogWorkerImpl { + SharedLogWorkerImpl(const std::string& log_prefix, const std::string& log_directory); + ~SharedLogWorkerImpl(); + + void backgroundFileWrite(MeehLog::internal::LogEntry message); + void backgroundExitFatal(MeehLog::internal::FatalMessage fatal_message); + std::string backgroundChangeLogFile(const std::string& directory); + std::string backgroundFileName(); + + std::string log_file_with_path_; + std::string log_prefix_backup_; // needed in case of future log file changes of directory + std::unique_ptr mBg; + std::unique_ptr mOutptr; + steady_time_point steady_start_time_; + +private: + SharedLogWorkerImpl& operator=(const SharedLogWorkerImpl&); + SharedLogWorkerImpl(const SharedLogWorkerImpl& other); + std::ofstream& filestream() {return *(mOutptr.get());} +}; + +// +// Private API implementation : SharedLogWorkerImpl +SharedLogWorkerImpl::SharedLogWorkerImpl(const std::string& log_prefix, const std::string& log_directory) +: log_file_with_path_(log_directory) +, log_prefix_backup_(log_prefix) +, mBg(MeehLog::Active::createActive()) +, mOutptr(new std::ofstream) +, steady_start_time_(std::chrono::steady_clock::now()) { // TODO: ha en timer function steadyTimer som har koll på start + log_prefix_backup_ = prefixSanityFix(log_prefix); + if (!isValidFilename(log_prefix_backup_)) { + // illegal prefix, refuse to start + std::cerr << "MeehLog: forced abort due to illegal log prefix [" << log_prefix << "]" << std::endl << std::flush; + abort(); + } + + std::string file_name = createLogFileName(log_prefix_backup_); + log_file_with_path_ = pathSanityFix(log_file_with_path_, file_name); + mOutptr = createLogFile(log_file_with_path_); + if (!mOutptr) { + std::cerr << "Cannot write logfile to location, attempting current directory" << std::endl; + log_file_with_path_ = "./" + file_name; + mOutptr = createLogFile(log_file_with_path_); + } + assert((mOutptr) && "cannot open log file at startup"); +} + + +SharedLogWorkerImpl::~SharedLogWorkerImpl() { + std::ostringstream ss_exit; + mBg.reset(); // flush the log queue + ss_exit << "\nMeehLog file shutdown at: " << MeehLog::localtime_formatted(systemtime_now(), time_formatted); + filestream() << ss_exit.str() << std::flush; +} + + +void SharedLogWorkerImpl::backgroundFileWrite(LogEntry message) { + using namespace std; + std::ofstream& out(filestream()); + auto log_time = message.mTimestamp; + auto steady_time = std::chrono::steady_clock::now(); + out << "\n" << MeehLog::localtime_formatted(log_time, date_formatted); + out << " " << MeehLog::localtime_formatted(log_time, time_formatted); + out << " " << chrono::duration_cast(steady_time - steady_start_time_).count(); + out << "\t" << message.mMsg << std::flush; +} + + +void SharedLogWorkerImpl::backgroundExitFatal(FatalMessage fatal_message) { + backgroundFileWrite(fatal_message.mMessage); + LogEntry flushEntry{"Log flushed successfully to disk \nExiting", MeehLog::internal::systemtime_now()}; + backgroundFileWrite(flushEntry); + std::cerr << "MeehLog exiting after receiving fatal event" << std::endl; + std::cerr << "Log file at: [" << log_file_with_path_ << "]\n" << std::endl << std::flush; + filestream().close(); + MeehLog::shutDownLogging(); // only an initialized logger can recieve a fatal message. So shutting down logging now is fine. + //exitWithDefaultSignalHandler(fatal_message.mSignalId); + perror("MeehLog exited after receiving FATAL trigger. Flush message status: "); // should never reach this point +} + + +std::string SharedLogWorkerImpl::backgroundChangeLogFile(const std::string& directory) { + std::string file_name = createLogFileName(log_prefix_backup_); + std::string prospect_log = directory + file_name; + std::unique_ptr log_stream = createLogFile(prospect_log); + if (nullptr == log_stream) { + LogEntry error("Unable to change log file. Illegal filename or busy? Unsuccessful log name was:" + prospect_log, MeehLog::internal::systemtime_now()); + backgroundFileWrite(error); + + return ""; // no success + } + + std::ostringstream ss_change; + ss_change << "\nChanging log file from : " << log_file_with_path_; + ss_change << "\nto new location: " << prospect_log << "\n"; + backgroundFileWrite({ss_change.str().c_str(), MeehLog::internal::systemtime_now()}); + ss_change.str(""); + + // setting the new log as active + std::string old_log = log_file_with_path_; + log_file_with_path_ = prospect_log; + mOutptr = std::move(log_stream); + ss_change << "\nNew log file. The previous log file was at: "; + ss_change << old_log; + backgroundFileWrite({ss_change.str(), MeehLog::internal::systemtime_now()}); + return log_file_with_path_; +} + +std::string SharedLogWorkerImpl::backgroundFileName() { + return log_file_with_path_; +} + + +// Public API implementation +// +SharedLogWorker::SharedLogWorker(const std::string& log_prefix, const std::string& log_directory) +: pimpl(new SharedLogWorkerImpl(log_prefix, log_directory)) +, logFileWithPath(pimpl->log_file_with_path_) { + assert((pimpl != nullptr) && "shouild never happen"); +} + +SharedLogWorker::~SharedLogWorker() { + pimpl.reset(); + MeehLog::shutDownLoggingForActiveOnly(this); + std::cerr << "\nExiting, log location: " << logFileWithPath << std::endl << std::flush; +} + +void SharedLogWorker::save(const MeehLog::internal::LogEntry& msg) { + pimpl->mBg->send(std::bind(&SharedLogWorkerImpl::backgroundFileWrite, pimpl.get(), msg)); +} + +void SharedLogWorker::fatal(MeehLog::internal::FatalMessage fatal_message) { + pimpl->mBg->send(std::bind(&SharedLogWorkerImpl::backgroundExitFatal, pimpl.get(), fatal_message)); +} + + +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wpessimizing-move" + +std::future SharedLogWorker::changeLogFile(const std::string& log_directory) { + MeehLog::Active* bgWorker = pimpl->mBg.get(); + auto mBgcall = [this, log_directory]() {return pimpl->backgroundChangeLogFile(log_directory);}; + auto future_result = MeehLog::spawn_task(mBgcall, bgWorker); + return std::move(future_result); +} + + +std::future SharedLogWorker::genericAsyncCall(std::function f) { + auto bgWorker = pimpl->mBg.get(); + auto future_result = MeehLog::spawn_task(f, bgWorker); + return std::move(future_result); +} + +std::future SharedLogWorker::logFileName() { + MeehLog::Active* bgWorker = pimpl->mBg.get(); + auto mBgcall = [&]() {return pimpl->backgroundFileName();}; + auto future_result = MeehLog::spawn_task(mBgcall , bgWorker); + return std::move(future_result); +} + +#pragma GCC diagnostic pop + diff --git a/launchers/macosx/LoggerWorker.hpp b/launchers/macosx/LoggerWorker.hpp new file mode 100644 index 000000000..24aead20c --- /dev/null +++ b/launchers/macosx/LoggerWorker.hpp @@ -0,0 +1,143 @@ +// +// LoggerWorker.hpp +// I2PLauncher +// +// Created by Mikal Villa on 27/09/2018. +// Copyright © 2018 The I2P Project. All rights reserved. +// Imported/Refactored from earlier C++ project of Meeh +// + +#ifndef LoggerWorker_hpp +#define LoggerWorker_hpp + +#ifdef __cplusplus + +#include +#include +#include +#include +#include +#include +#include + +#include "include/sharedqueue.h" +#include "Logger.h" + +struct SharedLogWorkerImpl; + + +namespace MeehLog { + typedef std::function Callback; + + class Active { + private: + Active(const Active&); + Active& operator=(const Active&); + Active(); // Construction ONLY through factory createActive(); + void doDone(){mDone = true;} + void run(); + + shared_queue mMq; + std::thread mThd; + bool mDone; // finished flag to be set through msg queue by ~Active + + + public: + virtual ~Active(); + void send(Callback msg_); + static std::unique_ptr createActive(); // Factory: safe construction & thread start + }; + + + + // A straightforward technique to move around packaged_tasks. + // Instances of std::packaged_task are MoveConstructible and MoveAssignable, but + // not CopyConstructible or CopyAssignable. To put them in a std container they need + // to be wrapped and their internals "moved" when tried to be copied. + template + struct MoveOnCopy { + mutable Moveable _move_only; + + explicit MoveOnCopy(Moveable&& m) : _move_only(std::move(m)) {} + MoveOnCopy(MoveOnCopy const& t) : _move_only(std::move(t._move_only)) {} + MoveOnCopy(MoveOnCopy&& t) : _move_only(std::move(t._move_only)) {} + + MoveOnCopy& operator=(MoveOnCopy const& other) { + _move_only = std::move(other._move_only); + return *this; + } + + MoveOnCopy& operator=(MoveOnCopy&& other) { + _move_only = std::move(other._move_only); + return *this; + } + + void operator()() { _move_only(); } + Moveable& get() { return _move_only; } + Moveable release() { return std::move(_move_only); } + }; + + // Generic helper function to avoid repeating the steps for managing + // asynchronous task job (by active object) that returns a future results + // could of course be made even more generic if done more in the way of + // std::async, ref: http://en.cppreference.com/w/cpp/thread/async + // + // Example usage: + // std::unique_ptr bgWorker{Active::createActive()}; + // ... + // auto msg_call=[=](){return ("Hello from the Background");}; + // auto future_msg = g2::spawn_task(msg_lambda, bgWorker.get()); + + template + std::future::type> spawn_task(Func func, Active* worker) { + typedef typename std::result_of::type result_type; + typedef std::packaged_task task_type; + task_type task(std::move(func)); + std::future result = task.get_future(); + + worker->send(MoveOnCopy(std::move(task))); + return std::move(result); + } +} + +class SharedLogWorker { +public: + /** + * \param log_prefix is the 'name' of the binary, this give the log name 'LOG-'name'-... + * \param log_directory gives the directory to put the log files */ + SharedLogWorker(const std::string& log_prefix, const std::string& log_directory); + virtual ~SharedLogWorker(); + + /// pushes in background thread (asynchronously) input messages to log file + void save(const MeehLog::internal::LogEntry& entry); + + /// Will push a fatal message on the queue, this is the last message to be processed + /// this way it's ensured that all existing entries were flushed before 'fatal' + /// Will abort the application! + void fatal(MeehLog::internal::FatalMessage fatal_message); + + /// Attempt to change the current log file to another name/location. + /// returns filename with full path if successful, else empty string + std::future changeLogFile(const std::string& log_directory); + + /// Does an independent action in FIFO order, compared to the normal LOG statements + /// Example: auto threadID = [] { std::cout << "thread id: " << std::this_thread::get_id() << std::endl; }; + /// auto call = logger.genericAsyncCall(threadID); + /// // this will print out the thread id of the background worker + std::future genericAsyncCall(std::function f); + + /// Probably only needed for unit-testing or specific log management post logging + /// request to get log name is processed in FIFO order just like any other background job. + std::future logFileName(); + +private: + std::unique_ptr pimpl; + const std::string logFileWithPath; + + SharedLogWorker(const SharedLogWorker&); + SharedLogWorker& operator=(const SharedLogWorker&); +}; + +#endif // __cplusplus + +#endif /* LoggerWorker_hpp */