feat(logging): better error logging with stack trace in lua

This commit is contained in:
maelstrom 2025-05-23 00:59:31 +02:00
parent cc87d08dad
commit 1cbb349e05
9 changed files with 98 additions and 6 deletions

View file

@ -4,10 +4,12 @@
#include <fstream> #include <fstream>
#include <chrono> #include <chrono>
#include <format> #include <format>
#include <string>
#include <vector> #include <vector>
static std::ofstream logStream; static std::ofstream logStream;
static std::vector<Logger::LogListener> logListeners; static std::vector<Logger::LogListener> logListeners;
static std::vector<Logger::TraceLogListener> traceLogListeners;
std::string Logger::currentLogDir = "NULL"; std::string Logger::currentLogDir = "NULL";
void Logger::init() { void Logger::init() {
@ -29,6 +31,7 @@ void Logger::finish() {
void Logger::log(std::string message, Logger::LogLevel logLevel) { void Logger::log(std::string message, Logger::LogLevel logLevel) {
std::string logLevelStr = logLevel == Logger::LogLevel::INFO ? "INFO" : std::string logLevelStr = logLevel == Logger::LogLevel::INFO ? "INFO" :
logLevel == Logger::LogLevel::DEBUG ? "DEBUG" : logLevel == Logger::LogLevel::DEBUG ? "DEBUG" :
logLevel == Logger::LogLevel::TRACE ? "TRACE" :
logLevel == Logger::LogLevel::WARNING ? "WARN" : logLevel == Logger::LogLevel::WARNING ? "WARN" :
logLevel == Logger::LogLevel::ERROR ? "ERROR" : logLevel == Logger::LogLevel::ERROR ? "ERROR" :
logLevel == Logger::LogLevel::FATAL_ERROR ? "FATAL" : "?"; logLevel == Logger::LogLevel::FATAL_ERROR ? "FATAL" : "?";
@ -49,6 +52,20 @@ void Logger::log(std::string message, Logger::LogLevel logLevel) {
} }
} }
void Logger::trace(std::string source, int line, void* userData) {
std::string message = "'" + source + "' Line " + std::to_string(line);
log(message, Logger::LogLevel::TRACE);
for (Logger::TraceLogListener listener : traceLogListeners) {
listener(message, source, line, userData);
}
}
void Logger::addLogListener(Logger::LogListener listener) { void Logger::addLogListener(Logger::LogListener listener) {
logListeners.push_back(listener); logListeners.push_back(listener);
} }
void Logger::addLogListener(Logger::TraceLogListener listener) {
traceLogListeners.push_back(listener);
}

View file

@ -8,18 +8,21 @@ namespace Logger {
enum class LogLevel { enum class LogLevel {
INFO, INFO,
DEBUG, DEBUG,
TRACE,
WARNING, WARNING,
ERROR, ERROR,
FATAL_ERROR, FATAL_ERROR,
}; };
typedef std::function<void(LogLevel logLeve, std::string message)> LogListener; typedef std::function<void(LogLevel logLevel, std::string message)> LogListener;
typedef std::function<void(std::string message, std::string source, int line, void* userData)> TraceLogListener;
extern std::string currentLogDir; extern std::string currentLogDir;
void init(); void init();
void finish(); void finish();
void addLogListener(LogListener); void addLogListener(LogListener);
void addLogListener(TraceLogListener);
void log(std::string message, LogLevel logLevel); void log(std::string message, LogLevel logLevel);
inline void info(std::string message) { log(message, LogLevel::INFO); } inline void info(std::string message) { log(message, LogLevel::INFO); }
@ -28,6 +31,10 @@ namespace Logger {
inline void error(std::string message) { log(message, LogLevel::ERROR); } inline void error(std::string message) { log(message, LogLevel::ERROR); }
inline void fatalError(std::string message) { log(message, LogLevel::FATAL_ERROR); } inline void fatalError(std::string message) { log(message, LogLevel::FATAL_ERROR); }
inline void traceStart() { log("Stack start", LogLevel::TRACE); }
inline void traceEnd() { log("Stack end", LogLevel::TRACE); }
void trace(std::string source, int line, void* userData = nullptr);
template <typename ...Args> template <typename ...Args>
void logf(std::string format, LogLevel logLevel, Args&&... args) { void logf(std::string format, LogLevel logLevel, Args&&... args) {
char message[200]; char message[200];

View file

@ -430,3 +430,16 @@ std::vector<std::pair<std::string, std::shared_ptr<Instance>>> Instance::GetRefe
return referenceProperties; return referenceProperties;
} }
std::string Instance::GetFullName() {
std::string currentName = name;
std::optional<std::shared_ptr<Instance>> currentParent = GetParent();
while (currentParent.has_value() && !currentParent.value()->IsA("DataModel")) {
currentName = currentParent.value()->name + "." + currentName;
currentParent = currentParent.value()->GetParent();
}
return currentName;
}

View file

@ -113,6 +113,7 @@ public:
// Utility functions // Utility functions
inline void AddChild(std::shared_ptr<Instance> object) { object->SetParent(this->shared_from_this()); } inline void AddChild(std::shared_ptr<Instance> object) { object->SetParent(this->shared_from_this()); }
std::optional<std::shared_ptr<Instance>> FindFirstChild(std::string); std::optional<std::shared_ptr<Instance>> FindFirstChild(std::string);
std::string GetFullName();
// Properties // Properties
result<Data::Variant, MemberNotFound> GetPropertyValue(std::string name); result<Data::Variant, MemberNotFound> GetPropertyValue(std::string name);

View file

@ -22,7 +22,8 @@ Script::Script(): Instance(&TYPE) {
"workspace.Part.TouchEnded:Connect(function(otherPart)\n" "workspace.Part.TouchEnded:Connect(function(otherPart)\n"
" print(\"Touched ended with: \", otherPart.Name)\n" " print(\"Touched ended with: \", otherPart.Name)\n"
"end)\n" "end)\n"
"\n"; "\n"
"error(\"Test\")";
} }
Script::~Script() { Script::~Script() {
@ -57,12 +58,39 @@ void Script::Run() {
lua_pop(Lt, 1); // _G lua_pop(Lt, 1); // _G
// Load source and push onto thread stack as function ptr // Load source and push onto thread stack as function ptr
luaL_loadstring(Lt, source.c_str()); // luaL_loadstring(Lt, source.c_str());
luaL_loadbuffer(Lt, source.c_str(), source.size(), scriptContext->RegisterScriptSource(shared<Script>()).c_str());
int status = lua_resume(Lt, 0); int status = lua_resume(Lt, 0);
if (status > LUA_YIELD) { if (status > LUA_YIELD) {
Logger::error(lua_tostring(Lt, -1)); lua_Debug dbg;
lua_getstack(Lt, 1, &dbg);
lua_getinfo(Lt, "S", &dbg);
std::weak_ptr<Script> source = scriptContext->GetScriptFromSource(dbg.source);
std::string errorMessage = lua_tostring(Lt, -1);
if (!source.expired())
errorMessage = source.lock()->GetFullName() + errorMessage.substr(errorMessage.find(':'));
Logger::error(errorMessage);
lua_pop(Lt, 1); // Pop return value lua_pop(Lt, 1); // Pop return value
Logger::traceStart();
int stack = 1;
while (lua_getstack(Lt, stack++, &dbg)) {
lua_getinfo(Lt, "nlSu", &dbg);
std::weak_ptr<Script> source = scriptContext->GetScriptFromSource(dbg.source);
if (source.expired()) {
Logger::trace(dbg.source, dbg.currentline);
} else {
Logger::trace(source.lock()->GetFullName(), dbg.currentline, &source);
}
}
Logger::traceEnd();
} }
lua_pop(L, 1); // Pop the thread lua_pop(L, 1); // Pop the thread

View file

@ -4,9 +4,8 @@
#include "datatypes/vector.h" #include "datatypes/vector.h"
#include "logger.h" #include "logger.h"
#include "timeutil.h" #include "timeutil.h"
#include <cstdint>
#include <ctime> #include <ctime>
#include <chrono> #include <string>
#include "lua.h" #include "lua.h"
static int g_print(lua_State*); static int g_print(lua_State*);
@ -130,6 +129,17 @@ void ScriptContext::RunSleepingThreads() {
} }
} }
std::string ScriptContext::RegisterScriptSource(std::shared_ptr<Script> script) {
int id = lastScriptSourceId++;
scriptSources[id] = script;
return "=f" + std::to_string(id);
}
std::weak_ptr<Script> ScriptContext::GetScriptFromSource(std::string source) {
int id = std::stoi(source.c_str() + 2);
return scriptSources[id];
}
// https://www.lua.org/source/5.1/lbaselib.c.html // https://www.lua.org/source/5.1/lbaselib.c.html
static int g_print(lua_State* L) { static int g_print(lua_State* L) {
std::string buf; std::string buf;

View file

@ -3,6 +3,7 @@
#include "objects/annotation.h" #include "objects/annotation.h"
#include "objects/base/service.h" #include "objects/base/service.h"
#include "lua.h" #include "lua.h"
#include <memory>
#include <vector> #include <vector>
struct SleepingThread { struct SleepingThread {
@ -12,10 +13,14 @@ struct SleepingThread {
bool active = true; bool active = true;
}; };
class Script;
class DEF_INST_SERVICE ScriptContext : public Service { class DEF_INST_SERVICE ScriptContext : public Service {
AUTOGEN_PREAMBLE AUTOGEN_PREAMBLE
std::vector<SleepingThread> sleepingThreads; std::vector<SleepingThread> sleepingThreads;
std::map<int, std::weak_ptr<Script>> scriptSources;
int lastScriptSourceId = 0;
protected: protected:
void InitService() override; void InitService() override;
bool initialized = false; bool initialized = false;
@ -27,6 +32,8 @@ public:
lua_State* state; lua_State* state;
void PushThreadSleep(lua_State* thread, float delay); void PushThreadSleep(lua_State* thread, float delay);
void RunSleepingThreads(); void RunSleepingThreads();
std::string RegisterScriptSource(std::shared_ptr<Script>);
std::weak_ptr<Script> GetScriptFromSource(std::string source);
static inline std::shared_ptr<Instance> Create() { return std::make_shared<ScriptContext>(); }; static inline std::shared_ptr<Instance> Create() { return std::make_shared<ScriptContext>(); };
}; };

View file

@ -82,6 +82,7 @@ MainWindow::MainWindow(QWidget *parent)
// Logger // Logger
Logger::addLogListener(std::bind(&MainWindow::handleLog, this, std::placeholders::_1, std::placeholders::_2)); Logger::addLogListener(std::bind(&MainWindow::handleLog, this, std::placeholders::_1, std::placeholders::_2));
Logger::addLogListener(std::bind(&MainWindow::handleLogTrace, this, std::placeholders::_1, std::placeholders::_2, std::placeholders::_3, std::placeholders::_4));
QFont font(""); QFont font("");
font.setStyleHint(QFont::Monospace); font.setStyleHint(QFont::Monospace);
@ -161,12 +162,19 @@ void MainWindow::handleLog(Logger::LogLevel logLevel, std::string message) {
if (logLevel == Logger::LogLevel::INFO) if (logLevel == Logger::LogLevel::INFO)
ui->outputTextView->appendHtml(QString("<p>%1</p>").arg(QString::fromStdString(message))); ui->outputTextView->appendHtml(QString("<p>%1</p>").arg(QString::fromStdString(message)));
if (logLevel == Logger::LogLevel::TRACE)
ui->outputTextView->appendHtml(QString("<p style=\"color:rgb(0, 127, 255);\">%1</p>").arg(QString::fromStdString(message)));
if (logLevel == Logger::LogLevel::WARNING) if (logLevel == Logger::LogLevel::WARNING)
ui->outputTextView->appendHtml(QString("<p style=\"color:rgb(255, 127, 0); font-weight: bold;\">%1</p>").arg(QString::fromStdString(message))); ui->outputTextView->appendHtml(QString("<p style=\"color:rgb(255, 127, 0); font-weight: bold;\">%1</p>").arg(QString::fromStdString(message)));
if (logLevel == Logger::LogLevel::ERROR || logLevel == Logger::LogLevel::FATAL_ERROR) if (logLevel == Logger::LogLevel::ERROR || logLevel == Logger::LogLevel::FATAL_ERROR)
ui->outputTextView->appendHtml(QString("<p style=\"color:rgb(255, 0, 0); font-weight: bold;\">%1</p>").arg(QString::fromStdString(message))); ui->outputTextView->appendHtml(QString("<p style=\"color:rgb(255, 0, 0); font-weight: bold;\">%1</p>").arg(QString::fromStdString(message)));
} }
void MainWindow::handleLogTrace(std::string message, std::string source, int line, void* userData) {
}
void MainWindow::connectActionHandlers() { void MainWindow::connectActionHandlers() {
// Explorer View // Explorer View

View file

@ -65,6 +65,7 @@ private:
void updateToolbars(); void updateToolbars();
void closeEvent(QCloseEvent* evt) override; void closeEvent(QCloseEvent* evt) override;
void handleLog(Logger::LogLevel, std::string); void handleLog(Logger::LogLevel, std::string);
void handleLogTrace(std::string, std::string, int, void*);
void connectActionHandlers(); void connectActionHandlers();