From 2139d7d45fb1a8ed250ad96c9975c581f02f72a9 Mon Sep 17 00:00:00 2001 From: ShadowNinja Date: Tue, 13 Oct 2015 03:57:44 -0400 Subject: [PATCH] Refactor logging - Add warning log level - Change debug_log_level setting to enumeration string - Map Irrlicht log events to MT log events - Encapsulate log_* functions and global variables into a class, Logger - Unify dstream with standard logging mechanism - Unify core.debug() with standard core.log() script API --- builtin/common/strict.lua | 14 +- builtin/fstk/ui.lua | 6 +- builtin/game/deprecated.lua | 13 +- builtin/game/register.lua | 2 +- builtin/init.lua | 2 +- doc/lua_api.txt | 10 +- minetest.conf.example | 5 +- src/client/clientlauncher.cpp | 26 +-- src/client/clientlauncher.h | 4 +- src/client/inputhandler.h | 20 +- src/debug.cpp | 137 +---------- src/debug.h | 31 +-- src/defaultsettings.cpp | 2 +- src/game.cpp | 5 +- src/gameparams.h | 9 +- src/log.cpp | 421 +++++++++++++++++++++------------- src/log.h | 194 ++++++++++++---- src/logoutputbuffer.h | 58 ----- src/main.cpp | 121 +++++----- src/minimap.cpp | 3 +- src/script/lua_api/l_util.cpp | 60 ++--- src/script/lua_api/l_util.h | 4 - src/threading/thread.cpp | 4 +- src/unittest/test.cpp | 11 +- src/unittest/test.h | 89 +++---- 25 files changed, 599 insertions(+), 652 deletions(-) delete mode 100644 src/logoutputbuffer.h diff --git a/builtin/common/strict.lua b/builtin/common/strict.lua index c7b86461..05ceadf7 100644 --- a/builtin/common/strict.lua +++ b/builtin/common/strict.lua @@ -9,11 +9,6 @@ function core.global_exists(name) end -local function warn(message) - print(os.date("%H:%M:%S: WARNING: ")..message) -end - - local meta = {} local declared = {} -- Key is source file, line, and variable name; seperated by NULs @@ -27,7 +22,7 @@ function meta:__newindex(name, value) info.currentline, name) if not warned[warn_key] and info.what ~= "main" and info.what ~= "C" then - warn(("Assignment to undeclared ".. + core.log("warning", ("Assignment to undeclared ".. "global %q inside a function at %s.") :format(name, desc)) warned[warn_key] = true @@ -35,9 +30,8 @@ function meta:__newindex(name, value) declared[name] = true end -- Ignore mod namespaces - if WARN_INIT and (not core.get_current_modname or - name ~= core.get_current_modname()) then - warn(("Global variable %q created at %s.") + if WARN_INIT and name ~= core.get_current_modname() then + core.log("warning", ("Global variable %q created at %s.") :format(name, desc)) end rawset(self, name, value) @@ -48,7 +42,7 @@ function meta:__index(name) local info = debug.getinfo(2, "Sl") local warn_key = ("%s\0%d\0%s"):format(info.source, info.currentline, name) if not declared[name] and not warned[warn_key] and info.what ~= "C" then - warn(("Undeclared global variable %q accessed at %s:%s") + core.log("warning", ("Undeclared global variable %q accessed at %s:%s") :format(name, info.short_src, info.currentline)) warned[warn_key] = true end diff --git a/builtin/fstk/ui.lua b/builtin/fstk/ui.lua index 8128c503..3ac0386c 100644 --- a/builtin/fstk/ui.lua +++ b/builtin/fstk/ui.lua @@ -127,11 +127,13 @@ function ui.update() end if (active_toplevel_ui_elements > 1) then - print("WARNING: ui manager detected more then one active ui element, self most likely isn't intended") + core.log("warning", "more than one active ui ".. + "element, self most likely isn't intended") end if (active_toplevel_ui_elements == 0) then - print("WARNING: not a single toplevel ui element active switching to default") + core.log("warning", "no toplevel ui element ".. + "active; switching to default") ui.childlist[ui.default]:show() formspec = ui.childlist[ui.default]:get_formspec() end diff --git a/builtin/game/deprecated.lua b/builtin/game/deprecated.lua index 405e599d..cd1cf5e2 100644 --- a/builtin/game/deprecated.lua +++ b/builtin/game/deprecated.lua @@ -4,8 +4,7 @@ -- Default material types -- local function digprop_err() - core.log("info", debug.traceback()) - core.log("info", "WARNING: The core.digprop_* functions are obsolete and need to be replaced by item groups.") + core.log("deprecated", "The core.digprop_* functions are obsolete and need to be replaced by item groups.") end core.digprop_constanttime = digprop_err @@ -16,12 +15,12 @@ core.digprop_woodlike = digprop_err core.digprop_leaveslike = digprop_err core.digprop_glasslike = digprop_err -core.node_metadata_inventory_move_allow_all = function() - core.log("info", "WARNING: core.node_metadata_inventory_move_allow_all is obsolete and does nothing.") +function core.node_metadata_inventory_move_allow_all() + core.log("deprecated", "core.node_metadata_inventory_move_allow_all is obsolete and does nothing.") end -core.add_to_creative_inventory = function(itemstring) - core.log('info', "WARNING: core.add_to_creative_inventory: This function is deprecated and does nothing.") +function core.add_to_creative_inventory(itemstring) + core.log("deprecated", "core.add_to_creative_inventory: This function is deprecated and does nothing.") end -- @@ -32,7 +31,7 @@ local envref_deprecation_message_printed = false setmetatable(core.env, { __index = function(table, key) if not envref_deprecation_message_printed then - core.log("info", "WARNING: core.env:[...] is deprecated and should be replaced with core.[...]") + core.log("deprecated", "core.env:[...] is deprecated and should be replaced with core.[...]") envref_deprecation_message_printed = true end local func = core[key] diff --git a/builtin/game/register.lua b/builtin/game/register.lua index d0e04bfc..840ade12 100644 --- a/builtin/game/register.lua +++ b/builtin/game/register.lua @@ -221,7 +221,7 @@ function core.register_alias(name, convert_to) error("Unable to register alias: Name is forbidden: " .. name) end if core.registered_items[name] ~= nil then - core.log("WARNING: Not registering alias, item with same name" .. + core.log("warning", "Not registering alias, item with same name" .. " is already defined: " .. name .. " -> " .. convert_to) else --core.log("Registering alias: " .. name .. " -> " .. convert_to) diff --git a/builtin/init.lua b/builtin/init.lua index 095771d1..02fb9db9 100644 --- a/builtin/init.lua +++ b/builtin/init.lua @@ -6,7 +6,7 @@ -- -- Initialize some very basic things -print = core.debug +function core.debug(...) core.log(table.concat({...}, "\t")) end math.randomseed(os.time()) os.setlocale("C", "numeric") minetest = core diff --git a/doc/lua_api.txt b/doc/lua_api.txt index 92628297..f0f70d07 100644 --- a/doc/lua_api.txt +++ b/doc/lua_api.txt @@ -1774,11 +1774,11 @@ Helper functions * false: return only file names. ### Logging -* `minetest.debug(line)` - * Always printed to `stderr` and logfile (`print()` is redirected here) -* `minetest.log(line)` -* `minetest.log(loglevel, line)` - * `loglevel` is one of `"error"`, `"action"`, `"info"`, `"verbose"` +* `minetest.debug(...)` + * Equivalent to `minetest.log(table.concat({...}, "\t"))` +* `minetest.log([level,] text)` + * `level` is one of `"none"`, `"error"`, `"warning"`, `"action"`, + `"info"`, or `"verbose"`. Default is `"none"`. ### Registration functions Call these functions only at load time! diff --git a/minetest.conf.example b/minetest.conf.example index 695e413c..15d0abbf 100644 --- a/minetest.conf.example +++ b/minetest.conf.example @@ -612,8 +612,9 @@ #remote_media = # Level of logging to be written to debug.txt: -# 0 = none, 1 = errors and debug, 2 = action, 3 = info, 4 = verbose. -#debug_log_level = 2 +# (no logging), none (messages with no level), error, +# warning, action, info, or verbose. +#debug_log_level = action # Maximum number of blocks that can be queued for loading #emergequeue_limit_total = 256 diff --git a/src/client/clientlauncher.cpp b/src/client/clientlauncher.cpp index 60eb2167..772bbaf2 100644 --- a/src/client/clientlauncher.cpp +++ b/src/client/clientlauncher.cpp @@ -89,7 +89,7 @@ bool ClientLauncher::run(GameParams &game_params, const Settings &cmd_args) if (list_video_modes) return print_video_modes(); - if (!init_engine(game_params.log_level)) { + if (!init_engine()) { errorstream << "Could not initialize game engine." << std::endl; return false; } @@ -321,10 +321,10 @@ void ClientLauncher::init_args(GameParams &game_params, const Settings &cmd_args || cmd_args.getFlag("random-input"); } -bool ClientLauncher::init_engine(int log_level) +bool ClientLauncher::init_engine() { receiver = new MyEventReceiver(); - create_engine_device(log_level); + create_engine_device(); return device != NULL; } @@ -455,7 +455,7 @@ bool ClientLauncher::launch_game(std::string &error_message, if (game_params.game_spec.isValid() && game_params.game_spec.id != worldspec.gameid) { - errorstream << "WARNING: Overriding gamespec from \"" + warningstream << "Overriding gamespec from \"" << worldspec.gameid << "\" to \"" << game_params.game_spec.id << "\"" << std::endl; gamespec = game_params.game_spec; @@ -500,20 +500,8 @@ void ClientLauncher::main_menu(MainMenuData *menudata) smgr->clear(); /* leave scene manager in a clean state */ } -bool ClientLauncher::create_engine_device(int log_level) +bool ClientLauncher::create_engine_device() { - static const irr::ELOG_LEVEL irr_log_level[5] = { - ELL_NONE, - ELL_ERROR, - ELL_WARNING, - ELL_INFORMATION, -#if (IRRLICHT_VERSION_MAJOR == 1 && IRRLICHT_VERSION_MINOR < 8) - ELL_INFORMATION -#else - ELL_DEBUG -#endif - }; - // Resolution selection bool fullscreen = g_settings->getBool("fullscreen"); u16 screenW = g_settings->getU16("screenW"); @@ -561,10 +549,6 @@ bool ClientLauncher::create_engine_device(int log_level) device = createDeviceEx(params); if (device) { - // Map our log level to irrlicht engine one. - ILogger* irr_logger = device->getLogger(); - irr_logger->setLogLevel(irr_log_level[log_level]); - porting::initIrrlicht(device); } diff --git a/src/client/clientlauncher.h b/src/client/clientlauncher.h index 49ceefc5..b10bbebc 100644 --- a/src/client/clientlauncher.h +++ b/src/client/clientlauncher.h @@ -90,13 +90,13 @@ public: protected: void init_args(GameParams &game_params, const Settings &cmd_args); - bool init_engine(int log_level); + bool init_engine(); bool launch_game(std::string &error_message, bool reconnect_requested, GameParams &game_params, const Settings &cmd_args); void main_menu(MainMenuData *menudata); - bool create_engine_device(int log_level); + bool create_engine_device(); void speed_tests(); bool print_video_modes(); diff --git a/src/client/inputhandler.h b/src/client/inputhandler.h index a894e35a..69e4b25f 100644 --- a/src/client/inputhandler.h +++ b/src/client/inputhandler.h @@ -17,8 +17,8 @@ with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. */ -#ifndef __INPUT_HANDLER_H__ -#define __INPUT_HANDLER_H__ +#ifndef INPUT_HANDLER_H +#define INPUT_HANDLER_H #include "irrlichttypes_extrabloated.h" @@ -86,16 +86,16 @@ public: } } } else if (event.EventType == irr::EET_LOG_TEXT_EVENT) { - static const enum LogMessageLevel irr_loglev_conv[] = { - LMT_VERBOSE, // ELL_DEBUG - LMT_INFO, // ELL_INFORMATION - LMT_ACTION, // ELL_WARNING - LMT_ERROR, // ELL_ERROR - LMT_ERROR, // ELL_NONE + static const LogLevel irr_loglev_conv[] = { + LL_VERBOSE, // ELL_DEBUG + LL_INFO, // ELL_INFORMATION + LL_WARNING, // ELL_WARNING + LL_ERROR, // ELL_ERROR + LL_NONE, // ELL_NONE }; assert(event.LogEvent.Level < ARRLEN(irr_loglev_conv)); - log_printline(irr_loglev_conv[event.LogEvent.Level], - std::string("Irrlicht: ") + (const char *)event.LogEvent.Text); + g_logger.log(irr_loglev_conv[event.LogEvent.Level], + std::string("Irrlicht: ") + (const char*) event.LogEvent.Text); return true; } /* always return false in order to continue processing events */ diff --git a/src/debug.cpp b/src/debug.cpp index 3608f42d..82aa6d51 100644 --- a/src/debug.cpp +++ b/src/debug.cpp @@ -26,6 +26,7 @@ with this program; if not, write to the Free Software Foundation, Inc., #include #include #include +#include #include "threading/mutex.h" #include "threading/mutex_auto_lock.h" #include "config.h" @@ -36,99 +37,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "filesys.h" #endif -/* - Debug output -*/ - -#define DEBUGSTREAM_COUNT 2 - -FILE *g_debugstreams[DEBUGSTREAM_COUNT] = {stderr, NULL}; - -#define DEBUGPRINT(...)\ -{\ - for(int i=0; i::iterator - i = g_debug_stacks.begin(); - i != g_debug_stacks.end(); ++i) - { - DebugStack *stack = i->second; - - for(int i=0; iprint(g_debugstreams[i], true); - } - } + debug_stacks_print_to(errorstream); } DebugStacker::DebugStacker(const char *text) diff --git a/src/debug.h b/src/debug.h index 2ccbe58b..b7521fec 100644 --- a/src/debug.h +++ b/src/debug.h @@ -24,6 +24,7 @@ with this program; if not, write to the Free Software Foundation, Inc., #include #include #include "gettime.h" +#include "log.h" #if (defined(WIN32) || defined(_WIN32_WCE)) #define WIN32_LEAN_AND_MEAN @@ -36,9 +37,13 @@ with this program; if not, write to the Free Software Foundation, Inc., #endif #define __NORETURN __declspec(noreturn) #define __FUNCTION_NAME __FUNCTION__ + #define NORETURN __declspec(noreturn) + #define FUNCTION_NAME __FUNCTION__ #else #define __NORETURN __attribute__ ((__noreturn__)) #define __FUNCTION_NAME __PRETTY_FUNCTION__ + #define NORETURN __attribute__ ((__noreturn__)) + #define FUNCTION_NAME __PRETTY_FUNCTION__ #endif // Whether to catch all std::exceptions. @@ -50,30 +55,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #define CATCH_UNHANDLED_EXCEPTIONS 0 #endif -/* - Debug output -*/ - -#define DTIME (getTimestamp()+": ") - -extern void debugstreams_init(bool disable_stderr, const char *filename); -extern void debugstreams_deinit(); - -// This is used to redirect output to /dev/null -class Nullstream : public std::ostream { -public: - Nullstream(): - std::ostream(0) - { - } -private: -}; - -extern std::ostream dstream; -extern std::ostream dstream_no_stderr; -extern Nullstream dummyout; - - /* Abort program execution immediately */ __NORETURN extern void fatal_error_fn( @@ -108,6 +89,8 @@ __NORETURN extern void sanity_check_fn( void debug_set_exception_handler(); +#define DTIME "" + /* DebugStack */ diff --git a/src/defaultsettings.cpp b/src/defaultsettings.cpp index dd5332a3..ac62b206 100644 --- a/src/defaultsettings.cpp +++ b/src/defaultsettings.cpp @@ -279,7 +279,7 @@ void set_default_settings(Settings *settings) settings->setDefault("dedicated_server_step", "0.1"); settings->setDefault("ignore_world_load_errors", "false"); settings->setDefault("remote_media", ""); - settings->setDefault("debug_log_level", "2"); + settings->setDefault("debug_log_level", "action"); settings->setDefault("emergequeue_limit_total", "256"); settings->setDefault("emergequeue_limit_diskonly", "32"); settings->setDefault("emergequeue_limit_generate", "32"); diff --git a/src/game.cpp b/src/game.cpp index 840d627b..e966920a 100644 --- a/src/game.cpp +++ b/src/game.cpp @@ -40,7 +40,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "guiPasswordChange.h" #include "guiVolumeChange.h" #include "hud.h" -#include "logoutputbuffer.h" #include "mainmenumanager.h" #include "mapblock.h" #include "nodedef.h" // Needed for determining pointing to nodes @@ -1163,7 +1162,7 @@ static void updateChat(Client &client, f32 dtime, bool show_debug, ChatBackend &chat_backend, gui::IGUIStaticText *guitext_chat) { // Add chat log output for errors to be shown in chat - static LogOutputBuffer chat_log_error_buf(LMT_ERROR); + static LogOutputBuffer chat_log_error_buf(g_logger, LL_ERROR); // Get new messages from error log buffer while (!chat_log_error_buf.empty()) { @@ -2675,7 +2674,7 @@ void Game::processKeyboardInput(VolatileRunFlags *flags, // Print debug stacks dstream << "-----------------------------------------" << std::endl; - dstream << DTIME << "Printing debug stacks:" << std::endl; + dstream << "Printing debug stacks:" << std::endl; dstream << "-----------------------------------------" << std::endl; debug_stacks_print(); diff --git a/src/gameparams.h b/src/gameparams.h index b50e943d..bf9953c3 100644 --- a/src/gameparams.h +++ b/src/gameparams.h @@ -17,17 +17,18 @@ with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. */ -#ifndef __GAME_PARAMS_H__ -#define __GAME_PARAMS_H__ +#ifndef GAME_PARAMS_H +#define GAME_PARAMS_H -#include "irrlichttypes_extrabloated.h" +#include "irrlichttypes.h" + +struct SubgameSpec; struct GameParams { u16 socket_port; std::string world_path; SubgameSpec game_spec; bool is_dedicated_server; - int log_level; }; #endif diff --git a/src/log.cpp b/src/log.cpp index c584d126..4f77101f 100644 --- a/src/log.cpp +++ b/src/log.cpp @@ -19,19 +19,91 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "log.h" -#include -#include -#include -#include -#include "threads.h" #include "threading/mutex_auto_lock.h" #include "debug.h" #include "gettime.h" #include "porting.h" #include "config.h" +#include "exceptions.h" +#include "util/numeric.h" +#include "log.h" + +#include +#include +#include +#include +#include + +class StringBuffer : public std::streambuf { +public: + StringBuffer() {} + + int overflow(int c); + virtual void flush(const std::string &buf) = 0; + std::streamsize xsputn(const char *s, std::streamsize n); + void push_back(char c); + +private: + std::string buffer; +}; + + +class LogBuffer : public StringBuffer { +public: + LogBuffer(Logger &logger, LogLevel lev) : + logger(logger), + level(lev) + {} + + void flush(const std::string &buffer); + +private: + Logger &logger; + LogLevel level; +}; + + +class RawLogBuffer : public StringBuffer { +public: + void flush(const std::string &buffer); +}; + + +#ifdef __ANDROID__ +static unsigned int level_to_android[] = { + ANDROID_LOG_INFO, // LL_NONE + //ANDROID_LOG_FATAL, + ANDROID_LOG_ERROR, // LL_ERROR + ANDROID_LOG_WARN, // LL_WARNING + ANDROID_LOG_WARN, // LL_ACTION + //ANDROID_LOG_INFO, + ANDROID_LOG_DEBUG, // LL_INFO + ANDROID_LOG_VERBOSE, // LL_VERBOSE + +}; +#endif + +//// +//// Globals +//// + +Logger g_logger; + +StreamLogOutput stdout_output(std::cout); +StreamLogOutput stderr_output(std::cerr); +std::ostream null_stream(NULL); + +RawLogBuffer raw_buf; + +LogBuffer none_buf(g_logger, LL_NONE); +LogBuffer error_buf(g_logger, LL_ERROR); +LogBuffer warning_buf(g_logger, LL_WARNING); +LogBuffer action_buf(g_logger, LL_ACTION); +LogBuffer info_buf(g_logger, LL_INFO); +LogBuffer verbose_buf(g_logger, LL_VERBOSE); // Connection -std::ostream *dout_con_ptr = &dummyout; +std::ostream *dout_con_ptr = &null_stream; std::ostream *derr_con_ptr = &verbosestream; // Server @@ -44,170 +116,211 @@ std::ostream *dout_client_ptr = &infostream; std::ostream *derr_client_ptr = &errorstream; #endif -#ifdef __ANDROID__ -unsigned int android_log_level_mapping[] = { - /* LMT_ERROR */ ANDROID_LOG_ERROR, - /* LMT_ACTION */ ANDROID_LOG_WARN, - /* LMT_INFO */ ANDROID_LOG_INFO, - /* LMT_VERBOSE */ ANDROID_LOG_VERBOSE +std::ostream rawstream(&raw_buf); +std::ostream dstream(&none_buf); +std::ostream errorstream(&error_buf); +std::ostream warningstream(&warning_buf); +std::ostream actionstream(&action_buf); +std::ostream infostream(&info_buf); +std::ostream verbosestream(&verbose_buf); + + +/////////////////////////////////////////////////////////////////////////////// + + +//// +//// Logger +//// + +LogLevel Logger::stringToLevel(const std::string &name) +{ + if (name == "none") + return LL_NONE; + else if (name == "error") + return LL_ERROR; + else if (name == "warning") + return LL_WARNING; + else if (name == "action") + return LL_ACTION; + else if (name == "info") + return LL_INFO; + else if (name == "verbose") + return LL_VERBOSE; + else + return LL_MAX; +} + +void Logger::addOutput(ILogOutput *out) +{ + addOutputMaxLevel(out, LL_MAX); +} + +void Logger::addOutput(ILogOutput *out, LogLevel lev) +{ + m_outputs[lev].push_back(out); +} + +void Logger::addOutputMaxLevel(ILogOutput *out, LogLevel lev) +{ + for (size_t i = 0; i <= lev; i++) + m_outputs[i].push_back(out); +} + +void Logger::removeOutput(ILogOutput *out) +{ + for (size_t i = 0; i < LL_MAX; i++) { + std::vector::iterator it; + + it = std::find(m_outputs[i].begin(), m_outputs[i].end(), out); + if (it != m_outputs[i].end()) + m_outputs[i].erase(it); + } +} + +void Logger::setLevelSilenced(LogLevel lev, bool silenced) +{ + m_silenced_levels[lev] = silenced; +} + +void Logger::registerThread(const std::string &name) +{ + threadid_t id = get_current_thread_id(); + MutexAutoLock lock(m_mutex); + m_thread_names[id] = name; +} + +void Logger::deregisterThread() +{ + threadid_t id = get_current_thread_id(); + MutexAutoLock lock(m_mutex); + m_thread_names.erase(id); +} + +const std::string Logger::getLevelLabel(LogLevel lev) +{ + static const std::string names[] = { + "", + "ERROR", + "WARNING", + "ACTION", + "INFO", + "VERBOSE", }; -#endif - -std::vector log_outputs[LMT_NUM_VALUES]; -std::map log_thread_names; -Mutex log_thread_name_mutex; - -void log_add_output(ILogOutput *out, enum LogMessageLevel lev) -{ - log_outputs[lev].push_back(out); + assert(lev < LL_MAX && lev >= 0); + assert(ARRLEN(names) == LL_MAX); + return names[lev]; } -void log_add_output_maxlev(ILogOutput *out, enum LogMessageLevel lev) +const std::string Logger::getThreadName() { - for(int i=0; i<=lev; i++) - log_outputs[i].push_back(out); -} + std::map::const_iterator it; -void log_add_output_all_levs(ILogOutput *out) -{ - for(int i=0; i::iterator it = - std::find(log_outputs[i].begin(), log_outputs[i].end(), out); - if(it != log_outputs[i].end()) - log_outputs[i].erase(it); - } -} - -void log_set_lev_silence(enum LogMessageLevel lev, bool silence) -{ - MutexAutoLock lock(log_thread_name_mutex); - - for (std::vector::iterator it = log_outputs[lev].begin(); - it != log_outputs[lev].end(); ++it) { - ILogOutput *out = *it; - out->silence = silence; - } -} - -void log_register_thread(const std::string &name) -{ threadid_t id = get_current_thread_id(); - MutexAutoLock lock(log_thread_name_mutex); + it = m_thread_names.find(id); + if (it != m_thread_names.end()) + return it->second; - log_thread_names[id] = name; + std::ostringstream os; + os << "#0x" << std::hex << id; + return os.str(); } -void log_deregister_thread() +void Logger::log(LogLevel lev, const std::string &text) { - threadid_t id = get_current_thread_id(); - MutexAutoLock lock(log_thread_name_mutex); + if (m_silenced_levels[lev]) + return; - log_thread_names.erase(id); -} - -static std::string get_lev_string(enum LogMessageLevel lev) -{ - switch(lev){ - case LMT_ERROR: - return "ERROR"; - case LMT_ACTION: - return "ACTION"; - case LMT_INFO: - return "INFO"; - case LMT_VERBOSE: - return "VERBOSE"; - case LMT_NUM_VALUES: - break; - } - return "(unknown level)"; -} - -void log_printline(enum LogMessageLevel lev, const std::string &text) -{ - MutexAutoLock lock(log_thread_name_mutex); - std::string threadname = "(unknown thread)"; - std::map::const_iterator i; - i = log_thread_names.find(get_current_thread_id()); - if(i != log_thread_names.end()) - threadname = i->second; - std::string levelname = get_lev_string(lev); + const std::string thread_name = getThreadName(); + const std::string label = getLevelLabel(lev); std::ostringstream os(std::ios_base::binary); - os << getTimestamp() << ": " << levelname << "["<::iterator i = log_outputs[lev].begin(); - i != log_outputs[lev].end(); ++i) { - ILogOutput *out = *i; - if (out->silence) - continue; + logToSystem(lev, text); + logToOutputs(lev, os.str()); +} - out->printLog(os.str()); - out->printLog(os.str(), lev); - out->printLog(lev, text); +void Logger::logRaw(LogLevel lev, const std::string &text) +{ + if (m_silenced_levels[lev]) + return; + + logToSystem(lev, text); + logToOutputs(lev, text); +} + +void Logger::logToSystem(LogLevel lev, const std::string &text) +{ +#ifdef __ANDROID__ + assert(ARRLEN(level_to_android) == LL_MAX); + __android_log_print(level_to_android[lev], + PROJECT_NAME_C, "%s", text.c_str()); +#endif +} + +void Logger::logToOutputs(LogLevel lev, const std::string &text) +{ + MutexAutoLock lock(m_mutex); + for (size_t i = 0; i != m_outputs[lev].size(); i++) + m_outputs[lev][i]->log(text); +} + + +//// +//// *LogOutput methods +//// + +void FileLogOutput::open(const std::string &filename) +{ + stream.open(filename.c_str(), std::ios::app | std::ios::ate); + if (!stream.good()) + throw FileNotGoodException("Failed to open log file " + + filename + ": " + strerror(errno)); + stream << "\n\n" + "-------------" << std::endl + << " Separator" << std::endl + << "-------------\n" << std::endl; +} + + + +//// +//// *Buffer methods +//// + +int StringBuffer::overflow(int c) +{ + push_back(c); + return c; +} + + +std::streamsize StringBuffer::xsputn(const char *s, std::streamsize n) +{ + for (int i = 0; i < n; ++i) + push_back(s[i]); + return n; +} + +void StringBuffer::push_back(char c) +{ + if (c == '\n' || c == '\r') { + if (!buffer.empty()) + flush(buffer); + buffer.clear(); + } else { + buffer.push_back(c); } } -class Logbuf : public std::streambuf + + + +void LogBuffer::flush(const std::string &buffer) { -public: - Logbuf(enum LogMessageLevel lev): - m_lev(lev) - { - } - - ~Logbuf() - { - } - - int overflow(int c) - { - bufchar(c); - return c; - } - std::streamsize xsputn(const char *s, std::streamsize n) - { - for(int i=0; i +#include #include +#include +#include "threads.h" -/* - Use this for logging everything. +class ILogOutput; - If you need to explicitly print something, use dstream or cout or cerr. -*/ - -enum LogMessageLevel { - LMT_ERROR, /* Something failed ("invalid map data on disk, block (2,2,1)") */ - LMT_ACTION, /* In-game actions ("celeron55 placed block at (12,4,-5)") */ - LMT_INFO, /* More deep info ("saving map on disk (only_modified=true)") */ - LMT_VERBOSE, /* Flood-style ("loaded block (2,2,2) from disk") */ - LMT_NUM_VALUES, +enum LogLevel { + LL_NONE, // Special level that is always printed + LL_ERROR, + LL_WARNING, + LL_ACTION, // In-game actions + LL_INFO, + LL_VERBOSE, + LL_MAX, }; -class ILogOutput -{ +class Logger { public: - ILogOutput() : - silence(false) - {} + void addOutput(ILogOutput *out); + void addOutput(ILogOutput *out, LogLevel lev); + void addOutputMaxLevel(ILogOutput *out, LogLevel lev); + void removeOutput(ILogOutput *out); + void setLevelSilenced(LogLevel lev, bool silenced); - /* line: Full line with timestamp, level and thread */ - virtual void printLog(const std::string &line){}; - /* line: Full line with timestamp, level and thread */ - virtual void printLog(const std::string &line, enum LogMessageLevel lev){}; - /* line: Only actual printed text */ - virtual void printLog(enum LogMessageLevel lev, const std::string &line){}; + void registerThread(const std::string &name); + void deregisterThread(); - bool silence; + void log(LogLevel lev, const std::string &text); + // Logs without a prefix + void logRaw(LogLevel lev, const std::string &text); + + void setTraceEnabled(bool enable) { m_trace_enabled = enable; } + bool getTraceEnabled() { return m_trace_enabled; } + + static LogLevel stringToLevel(const std::string &name); + +private: + void logToSystem(LogLevel, const std::string &text); + void logToOutputs(LogLevel, const std::string &text); + + const std::string getLevelLabel(LogLevel lev); + const std::string getThreadName(); + + std::vector m_outputs[LL_MAX]; + + // Should implement atomic loads and stores (even though it's only + // written to when one thread has access currently). + // Works on all known architectures (x86, ARM, MIPS). + volatile bool m_silenced_levels[LL_MAX]; + std::map m_thread_names; + mutable Mutex m_mutex; + bool m_trace_enabled; }; -void log_add_output(ILogOutput *out, enum LogMessageLevel lev); -void log_add_output_maxlev(ILogOutput *out, enum LogMessageLevel lev); -void log_add_output_all_levs(ILogOutput *out); -void log_remove_output(ILogOutput *out); -void log_set_lev_silence(enum LogMessageLevel lev, bool silence); +class ILogOutput { +public: + virtual void log(const std::string &line) = 0; +}; -void log_register_thread(const std::string &name); -void log_deregister_thread(); +class StreamLogOutput : public ILogOutput { +public: + StreamLogOutput(std::ostream &stream) : + stream(stream) + { + } -void log_printline(enum LogMessageLevel lev, const std::string &text); + void log(const std::string &line) + { + stream << line << std::endl; + } -#define LOGLINEF(lev, ...)\ -{\ - char buf[10000];\ - snprintf(buf, 10000, __VA_ARGS__);\ - log_printline(lev, buf);\ -} +private: + std::ostream &stream; +}; -extern std::ostream errorstream; -extern std::ostream actionstream; -extern std::ostream infostream; -extern std::ostream verbosestream; +class FileLogOutput : public ILogOutput { +public: + void open(const std::string &filename); -extern bool log_trace_level_enabled; + void log(const std::string &line) + { + stream << line << std::endl; + } -#define TRACESTREAM(x){ if(log_trace_level_enabled) verbosestream x; } -#define TRACEDO(x){ if(log_trace_level_enabled){ x ;} } +private: + std::ofstream stream; +}; + +class LogOutputBuffer : public ILogOutput { +public: + LogOutputBuffer(Logger &logger, LogLevel lev) : + logger(logger) + { + logger.addOutput(this, lev); + } + + ~LogOutputBuffer() + { + logger.removeOutput(this); + } + + virtual void log(const std::string &line) + { + buffer.push(line); + } + + bool empty() + { + return buffer.empty(); + } + + std::string get() + { + if (empty()) + return ""; + std::string s = buffer.front(); + buffer.pop(); + return s; + } + +private: + std::queue buffer; + Logger &logger; +}; + + +extern StreamLogOutput stdout_output; +extern StreamLogOutput stderr_output; +extern std::ostream null_stream; extern std::ostream *dout_con_ptr; extern std::ostream *derr_con_ptr; extern std::ostream *dout_server_ptr; extern std::ostream *derr_server_ptr; + +#ifndef SERVER +extern std::ostream *dout_client_ptr; +extern std::ostream *derr_client_ptr; +#endif + +extern Logger g_logger; + +// Writes directly to all LL_NONE log outputs for g_logger with no prefix. +extern std::ostream rawstream; + +extern std::ostream errorstream; +extern std::ostream warningstream; +extern std::ostream actionstream; +extern std::ostream infostream; +extern std::ostream verbosestream; +extern std::ostream dstream; + +#define TRACEDO(x) do { \ + if (g_logger.getTraceEnabled()) { \ + x; \ + } \ +} while (0) + +#define TRACESTREAM(x) TRACEDO(verbosestream x) + #define dout_con (*dout_con_ptr) #define derr_con (*derr_con_ptr) #define dout_server (*dout_server_ptr) #define derr_server (*derr_server_ptr) #ifndef SERVER -extern std::ostream *dout_client_ptr; -extern std::ostream *derr_client_ptr; -#define dout_client (*dout_client_ptr) -#define derr_client (*derr_client_ptr) - + #define dout_client (*dout_client_ptr) + #define derr_client (*derr_client_ptr) #endif -#endif +#endif diff --git a/src/logoutputbuffer.h b/src/logoutputbuffer.h deleted file mode 100644 index 69f06c44..00000000 --- a/src/logoutputbuffer.h +++ /dev/null @@ -1,58 +0,0 @@ -/* -Minetest -Copyright (C) 2013 celeron55, Perttu Ahola - -This program is free software; you can redistribute it and/or modify -it under the terms of the GNU Lesser General Public License as published by -the Free Software Foundation; either version 2.1 of the License, or -(at your option) any later version. - -This program is distributed in the hope that it will be useful, -but WITHOUT ANY WARRANTY; without even the implied warranty of -MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the -GNU Lesser General Public License for more details. - -You should have received a copy of the GNU Lesser General Public License along -with this program; if not, write to the Free Software Foundation, Inc., -51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. -*/ - -#ifndef LOGOUTPUTBUFFER_HEADER -#define LOGOUTPUTBUFFER_HEADER - -#include "log.h" -#include - -class LogOutputBuffer : public ILogOutput -{ -public: - LogOutputBuffer(LogMessageLevel maxlev) - { - log_add_output(this, maxlev); - } - ~LogOutputBuffer() - { - log_remove_output(this); - } - virtual void printLog(const std::string &line) - { - m_buf.push(line); - } - std::string get() - { - if(empty()) - return ""; - std::string s = m_buf.front(); - m_buf.pop(); - return s; - } - bool empty() - { - return m_buf.empty(); - } -private: - std::queue m_buf; -}; - -#endif - diff --git a/src/main.cpp b/src/main.cpp index dece2742..cc8b4bca 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -80,10 +80,10 @@ static void list_game_ids(); static void list_worlds(); static void setup_log_params(const Settings &cmd_args); static bool create_userdata_path(); -static bool init_common(int *log_level, const Settings &cmd_args, int argc, char *argv[]); +static bool init_common(const Settings &cmd_args, int argc, char *argv[]); static void startup_message(); static bool read_config_file(const Settings &cmd_args); -static void init_debug_streams(int *log_level, const Settings &cmd_args); +static void init_log_streams(const Settings &cmd_args); static bool game_configure(GameParams *game_params, const Settings &cmd_args); static void game_configure_port(GameParams *game_params, const Settings &cmd_args); @@ -122,25 +122,7 @@ u32 getTime(TimePrecision prec) #endif -class StderrLogOutput: public ILogOutput -{ -public: - /* line: Full line with timestamp, level and thread */ - void printLog(const std::string &line) - { - std::cerr << line << std::endl; - } -} main_stderr_log_out; - -class DstreamNoStderrLogOutput: public ILogOutput -{ -public: - /* line: Full line with timestamp, level and thread */ - void printLog(const std::string &line) - { - dstream_no_stderr << line << std::endl; - } -} main_dstream_no_stderr_log_out; +FileLogOutput file_log_output; static OptionList allowed_options; @@ -150,10 +132,8 @@ int main(int argc, char *argv[]) debug_set_exception_handler(); - log_add_output_maxlev(&main_stderr_log_out, LMT_ACTION); - log_add_output_all_levs(&main_dstream_no_stderr_log_out); - - log_register_thread("Main"); + g_logger.registerThread("Main"); + g_logger.addOutputMaxLevel(&stderr_output, LL_ACTION); Settings cmd_args; bool cmd_args_ok = get_cmdline_opts(argc, argv, &cmd_args); @@ -180,8 +160,7 @@ int main(int argc, char *argv[]) } // Initialize debug stacks - debug_stacks_init(); - DSTACK(__FUNCTION_NAME); + DSTACK(FUNCTION_NAME); // Debug handler BEGIN_DEBUG_EXCEPTION_HANDLER @@ -198,8 +177,7 @@ int main(int argc, char *argv[]) return 0; } - GameParams game_params; - if (!init_common(&game_params.log_level, cmd_args, argc, argv)) + if (!init_common(cmd_args, argc, argv)) return 1; #ifndef __ANDROID__ @@ -210,6 +188,7 @@ int main(int argc, char *argv[]) } #endif + GameParams game_params; #ifdef SERVER game_params.is_dedicated_server = true; #else @@ -219,7 +198,7 @@ int main(int argc, char *argv[]) if (!game_configure(&game_params, cmd_args)) return 1; - sanity_check(game_params.world_path != ""); + sanity_check(!game_params.world_path.empty()); infostream << "Using commanded world path [" << game_params.world_path << "]" << std::endl; @@ -247,7 +226,7 @@ int main(int argc, char *argv[]) // Stop httpfetch thread (if started) httpfetch_cleanup(); - END_DEBUG_EXCEPTION_HANDLER(errorstream) + END_DEBUG_EXCEPTION_HANDLER(errorstream); return retval; } @@ -403,26 +382,26 @@ static void setup_log_params(const Settings &cmd_args) { // Quiet mode, print errors only if (cmd_args.getFlag("quiet")) { - log_remove_output(&main_stderr_log_out); - log_add_output_maxlev(&main_stderr_log_out, LMT_ERROR); + g_logger.removeOutput(&stderr_output); + g_logger.addOutputMaxLevel(&stderr_output, LL_ERROR); } // If trace is enabled, enable logging of certain things if (cmd_args.getFlag("trace")) { dstream << _("Enabling trace level debug output") << std::endl; - log_trace_level_enabled = true; - dout_con_ptr = &verbosestream; // this is somewhat old crap - socket_enable_debug_output = true; // socket doesn't use log.h + g_logger.setTraceEnabled(true); + dout_con_ptr = &verbosestream; // This is somewhat old + socket_enable_debug_output = true; // Sockets doesn't use log.h } // In certain cases, output info level on stderr if (cmd_args.getFlag("info") || cmd_args.getFlag("verbose") || cmd_args.getFlag("trace") || cmd_args.getFlag("speedtests")) - log_add_output(&main_stderr_log_out, LMT_INFO); + g_logger.addOutput(&stderr_output, LL_INFO); // In certain cases, output verbose level on stderr if (cmd_args.getFlag("verbose") || cmd_args.getFlag("trace")) - log_add_output(&main_stderr_log_out, LMT_VERBOSE); + g_logger.addOutput(&stderr_output, LL_VERBOSE); } static bool create_userdata_path() @@ -450,7 +429,7 @@ static bool create_userdata_path() return success; } -static bool init_common(int *log_level, const Settings &cmd_args, int argc, char *argv[]) +static bool init_common(const Settings &cmd_args, int argc, char *argv[]) { startup_message(); set_default_settings(g_settings); @@ -462,7 +441,7 @@ static bool init_common(int *log_level, const Settings &cmd_args, int argc, char if (!read_config_file(cmd_args)) return false; - init_debug_streams(log_level, cmd_args); + init_log_streams(cmd_args); // Initialize random seed srand(time(0)); @@ -533,38 +512,47 @@ static bool read_config_file(const Settings &cmd_args) return true; } -static void init_debug_streams(int *log_level, const Settings &cmd_args) +static void init_log_streams(const Settings &cmd_args) { #if RUN_IN_PLACE - std::string logfile = DEBUGFILE; + std::string log_filename = DEBUGFILE; #else - std::string logfile = porting::path_user + DIR_DELIM + DEBUGFILE; + std::string log_filename = porting::path_user + DIR_DELIM + DEBUGFILE; #endif if (cmd_args.exists("logfile")) - logfile = cmd_args.get("logfile"); + log_filename = cmd_args.get("logfile"); - log_remove_output(&main_dstream_no_stderr_log_out); - *log_level = g_settings->getS32("debug_log_level"); + g_logger.removeOutput(&file_log_output); + std::string conf_loglev = g_settings->get("debug_log_level"); - if (*log_level == 0) //no logging - logfile = ""; - if (*log_level < 0) { - dstream << "WARNING: Supplied debug_log_level < 0; Using 0" << std::endl; - *log_level = 0; - } else if (*log_level > LMT_NUM_VALUES) { - dstream << "WARNING: Supplied debug_log_level > " << LMT_NUM_VALUES - << "; Using " << LMT_NUM_VALUES << std::endl; - *log_level = LMT_NUM_VALUES; + // Old integer format + if (std::isdigit(conf_loglev[0])) { + warningstream << "Deprecated use of debug_log_level with an " + "integer value; please update your configuration." << std::endl; + static const char *lev_name[] = + {"", "error", "action", "info", "verbose"}; + int lev_i = atoi(conf_loglev.c_str()); + if (lev_i < 0 || lev_i >= (int)ARRLEN(lev_name)) { + warningstream << "Supplied invalid debug_log_level!" + " Assuming action level." << std::endl; + lev_i = 2; + } + conf_loglev = lev_name[lev_i]; } - log_add_output_maxlev(&main_dstream_no_stderr_log_out, - (LogMessageLevel)(*log_level - 1)); + if (conf_loglev.empty()) // No logging + return; - debugstreams_init(false, logfile == "" ? NULL : logfile.c_str()); + LogLevel log_level = Logger::stringToLevel(conf_loglev); + if (log_level == LL_MAX) { + warningstream << "Supplied unrecognized debug_log_level; " + "using maximum." << std::endl; + } - infostream << "logfile = " << logfile << std::endl; + verbosestream << "log_filename = " << log_filename << std::endl; - atexit(debugstreams_deinit); + file_log_output.open(log_filename.c_str()); + g_logger.addOutputMaxLevel(&file_log_output, log_level); } static bool game_configure(GameParams *game_params, const Settings &cmd_args) @@ -678,10 +666,10 @@ static bool auto_select_world(GameParams *game_params) << world_path << "]" << std::endl; // If there are multiple worlds, list them } else if (worldspecs.size() > 1 && game_params->is_dedicated_server) { - dstream << _("Multiple worlds are available.") << std::endl; - dstream << _("Please select one using --worldname " + std::cerr << _("Multiple worlds are available.") << std::endl; + std::cerr << _("Please select one using --worldname " " or --world ") << std::endl; - print_worldspecs(worldspecs, dstream); + print_worldspecs(worldspecs, std::cerr); return false; // If there are no worlds, automatically create a new one } else { @@ -774,7 +762,7 @@ static bool determine_subgame(GameParams *game_params) if (game_params->game_spec.isValid()) { gamespec = game_params->game_spec; if (game_params->game_spec.id != world_gameid) { - errorstream << "WARNING: Using commanded gameid [" + warningstream << "Using commanded gameid [" << gamespec.id << "]" << " instead of world gameid [" << world_gameid << "]" << std::endl; } @@ -835,9 +823,8 @@ static bool run_dedicated_server(const GameParams &game_params, const Settings & return migrate_database(game_params, cmd_args); // Create server - Server server(game_params.world_path, - game_params.game_spec, false, bind_addr.isIPv6()); - + Server server(game_params.world_path, game_params.game_spec, false, + bind_addr.isIPv6()); server.start(bind_addr); // Run server diff --git a/src/minimap.cpp b/src/minimap.cpp index 7eb7247c..a6eff068 100644 --- a/src/minimap.cpp +++ b/src/minimap.cpp @@ -18,8 +18,6 @@ with this program; if not, write to the Free Software Foundation, Inc., */ #include "minimap.h" -#include -#include "logoutputbuffer.h" #include "threading/mutex_auto_lock.h" #include "threading/semaphore.h" #include "clientmap.h" @@ -28,6 +26,7 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "porting.h" #include "util/numeric.h" #include "util/string.h" +#include //// diff --git a/src/script/lua_api/l_util.cpp b/src/script/lua_api/l_util.cpp index 4b8b6d35..a4f01af0 100644 --- a/src/script/lua_api/l_util.cpp +++ b/src/script/lua_api/l_util.cpp @@ -26,7 +26,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "json/json.h" #include "cpp_api/s_security.h" #include "areastore.h" -#include "debug.h" #include "porting.h" #include "log.h" #include "tool.h" @@ -35,35 +34,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "util/auth.h" #include -// debug(...) -// Writes a line to dstream -int ModApiUtil::l_debug(lua_State *L) -{ - NO_MAP_LOCK_REQUIRED; - // Handle multiple parameters to behave like standard lua print() - int n = lua_gettop(L); - lua_getglobal(L, "tostring"); - for (int i = 1; i <= n; i++) { - /* - Call tostring(i-th argument). - This is what print() does, and it behaves a bit - differently from directly calling lua_tostring. - */ - lua_pushvalue(L, -1); /* function to be called */ - lua_pushvalue(L, i); /* value to print */ - lua_call(L, 1, 1); - size_t len; - const char *s = lua_tolstring(L, -1, &len); - if (i > 1) - dstream << "\t"; - if (s) - dstream << std::string(s, len); - lua_pop(L, 1); - } - dstream << std::endl; - return 0; -} - // log([level,] text) // Writes a line to the logger. // The one-argument version logs to infostream. @@ -72,26 +42,24 @@ int ModApiUtil::l_log(lua_State *L) { NO_MAP_LOCK_REQUIRED; std::string text; - LogMessageLevel level = LMT_INFO; + LogLevel level = LL_NONE; if (lua_isnone(L, 2)) { - text = lua_tostring(L, 1); - } - else { - std::string levelname = luaL_checkstring(L, 1); + text = luaL_checkstring(L, 1); + } else { + std::string name = luaL_checkstring(L, 1); text = luaL_checkstring(L, 2); - if(levelname == "error") - level = LMT_ERROR; - else if(levelname == "action") - level = LMT_ACTION; - else if(levelname == "verbose") - level = LMT_VERBOSE; - else if (levelname == "deprecated") { - log_deprecated(L,text); + if (name == "deprecated") { + log_deprecated(L, text); return 0; } - + level = Logger::stringToLevel(name); + if (level == LL_MAX) { + warningstream << "Tried to log at unknown level '" << name + << "'. Defaulting to \"none\"." << std::endl; + level = LL_NONE; + } } - log_printline(level, text); + g_logger.log(level, text); return 0; } @@ -390,7 +358,6 @@ int ModApiUtil::l_request_insecure_environment(lua_State *L) void ModApiUtil::Initialize(lua_State *L, int top) { - API_FCT(debug); API_FCT(log); API_FCT(setting_set); @@ -422,7 +389,6 @@ void ModApiUtil::Initialize(lua_State *L, int top) void ModApiUtil::InitializeAsync(AsyncEngine& engine) { - ASYNC_API_FCT(debug); ASYNC_API_FCT(log); //ASYNC_API_FCT(setting_set); diff --git a/src/script/lua_api/l_util.h b/src/script/lua_api/l_util.h index e75aa28c..4b55b196 100644 --- a/src/script/lua_api/l_util.h +++ b/src/script/lua_api/l_util.h @@ -35,10 +35,6 @@ private: GUIEngine instance should be in here. */ - // debug(text) - // Writes a line to dstream - static int l_debug(lua_State *L); - // log([level,] text) // Writes a line to the logger. // The one-argument version logs to infostream. diff --git a/src/threading/thread.cpp b/src/threading/thread.cpp index 73a95119..1f9b5479 100644 --- a/src/threading/thread.cpp +++ b/src/threading/thread.cpp @@ -222,11 +222,11 @@ void *Thread::theThread(void *param) th->running = true; th->setName(); - log_register_thread(th->name); + g_logger.registerThread(th->name); th->retval = th->run(); - log_deregister_thread(); + g_logger.deregisterThread(); th->running = false; #if __cplusplus < 201103L diff --git a/src/unittest/test.cpp b/src/unittest/test.cpp index d0ffb423..de471180 100644 --- a/src/unittest/test.cpp +++ b/src/unittest/test.cpp @@ -19,7 +19,6 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "test.h" -#include "debug.h" #include "log.h" #include "nodedef.h" #include "itemdef.h" @@ -223,7 +222,7 @@ void run_tests() u32 t1 = porting::getTime(PRECISION_MILLI); TestGameDef gamedef; - log_set_lev_silence(LMT_ERROR, true); + g_logger.setLevelSilenced(LL_ERROR, true); u32 num_modules_failed = 0; u32 num_total_tests_failed = 0; @@ -239,11 +238,11 @@ void run_tests() u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; - log_set_lev_silence(LMT_ERROR, false); + g_logger.setLevelSilenced(LL_ERROR, false); const char *overall_status = (num_modules_failed == 0) ? "PASSED" : "FAILED"; - dstream + rawstream << "++++++++++++++++++++++++++++++++++++++++" << "++++++++++++++++++++++++++++++++++++++++" << std::endl << "Unit Test Results: " << overall_status << std::endl @@ -264,14 +263,14 @@ void run_tests() bool TestBase::testModule(IGameDef *gamedef) { - dstream << "======== Testing module " << getName() << std::endl; + rawstream << "======== Testing module " << getName() << std::endl; u32 t1 = porting::getTime(PRECISION_MILLI); runTests(gamedef); u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; - dstream << "======== Module " << getName() << " " + rawstream << "======== Module " << getName() << " " << (num_tests_failed ? "failed" : "passed") << " (" << num_tests_failed << " failures / " << num_tests_run << " tests) - " << tdiff << "ms" << std::endl; diff --git a/src/unittest/test.h b/src/unittest/test.h index 47a441e0..f6c4711a 100644 --- a/src/unittest/test.h +++ b/src/unittest/test.h @@ -32,60 +32,61 @@ class TestFailedException : public std::exception { }; // Runs a unit test and reports results -#define TEST(fxn, ...) do { \ - u32 t1 = porting::getTime(PRECISION_MILLI); \ - try { \ - fxn(__VA_ARGS__); \ - dstream << "[PASS] "; \ - } catch (TestFailedException &e) { \ - dstream << "[FAIL] "; \ - num_tests_failed++; \ - } catch (std::exception &e) { \ - dstream << "Caught unhandled exception: " << e.what() << std::endl; \ - dstream << "[FAIL] "; \ - num_tests_failed++; \ - } \ - num_tests_run++; \ - u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; \ - dstream << #fxn << " - " << tdiff << "ms" << std::endl; \ +#define TEST(fxn, ...) do { \ + u32 t1 = porting::getTime(PRECISION_MILLI); \ + try { \ + fxn(__VA_ARGS__); \ + rawstream << "[PASS] "; \ + } catch (TestFailedException &e) { \ + rawstream << "[FAIL] "; \ + num_tests_failed++; \ + } catch (std::exception &e) { \ + rawstream << "Caught unhandled exception: " << e.what() << std::endl; \ + rawstream << "[FAIL] "; \ + num_tests_failed++; \ + } \ + num_tests_run++; \ + u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; \ + rawstream << #fxn << " - " << tdiff << "ms" << std::endl; \ } while (0) // Asserts the specified condition is true, or fails the current unit test -#define UASSERT(x) do { \ - if (!(x)) { \ - dstream << "Test assertion failed: " #x << std::endl \ - << " at " << fs::GetFilenameFromPath(__FILE__) \ - << ":" << __LINE__ << std::endl; \ - throw TestFailedException(); \ - } \ +#define UASSERT(x) do { \ + if (!(x)) { \ + rawstream << "Test assertion failed: " #x << std::endl \ + << " at " << fs::GetFilenameFromPath(__FILE__) \ + << ":" << __LINE__ << std::endl; \ + throw TestFailedException(); \ + } \ } while (0) // Asserts the specified condition is true, or fails the current unit test // and prints the format specifier fmt -#define UTEST(x, fmt, ...) do { \ - if (!(x)) { \ - char utest_buf[1024]; \ - snprintf(utest_buf, sizeof(utest_buf), fmt, __VA_ARGS__); \ - dstream << "Test assertion failed: " << utest_buf << std::endl \ - << " at " << fs::GetFilenameFromPath(__FILE__) \ - << ":" << __LINE__ << std::endl; \ - throw TestFailedException(); \ - } \ +#define UTEST(x, fmt, ...) do { \ + if (!(x)) { \ + char utest_buf[1024]; \ + snprintf(utest_buf, sizeof(utest_buf), fmt, __VA_ARGS__); \ + rawstream << "Test assertion failed: " << utest_buf << std::endl \ + << " at " << fs::GetFilenameFromPath(__FILE__) \ + << ":" << __LINE__ << std::endl; \ + throw TestFailedException(); \ + } \ } while (0) // Asserts the comparison specified by CMP is true, or fails the current unit test -#define UASSERTCMP(T, CMP, actual, expected) do { \ - T a = (actual); \ - T e = (expected); \ - if (!(a CMP e)) { \ - dstream << "Test assertion failed: " << #actual << " " << #CMP << " " \ - << #expected << std::endl \ - << " at " << fs::GetFilenameFromPath(__FILE__) << ":" \ - << __LINE__ << std::endl \ - << " actual: " << a << std::endl << " expected: " \ - << e << std::endl; \ - throw TestFailedException(); \ - } \ +#define UASSERTCMP(T, CMP, actual, expected) do { \ + T a = (actual); \ + T e = (expected); \ + if (!(a CMP e)) { \ + rawstream \ + << "Test assertion failed: " << #actual << " " << #CMP << " " \ + << #expected << std::endl \ + << " at " << fs::GetFilenameFromPath(__FILE__) << ":" \ + << __LINE__ << std::endl \ + << " actual: " << a << std::endl << " expected: " \ + << e << std::endl; \ + throw TestFailedException(); \ + } \ } while (0) #define UASSERTEQ(T, actual, expected) UASSERTCMP(T, ==, actual, expected)