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
This commit is contained in:
ShadowNinja 2015-10-13 03:57:44 -04:00 committed by kwolekr
parent e0b57c1140
commit 2139d7d45f
25 changed files with 599 additions and 652 deletions

@ -9,11 +9,6 @@ function core.global_exists(name)
end end
local function warn(message)
print(os.date("%H:%M:%S: WARNING: ")..message)
end
local meta = {} local meta = {}
local declared = {} local declared = {}
-- Key is source file, line, and variable name; seperated by NULs -- Key is source file, line, and variable name; seperated by NULs
@ -27,7 +22,7 @@ function meta:__newindex(name, value)
info.currentline, name) info.currentline, name)
if not warned[warn_key] and info.what ~= "main" and if not warned[warn_key] and info.what ~= "main" and
info.what ~= "C" then info.what ~= "C" then
warn(("Assignment to undeclared ".. core.log("warning", ("Assignment to undeclared "..
"global %q inside a function at %s.") "global %q inside a function at %s.")
:format(name, desc)) :format(name, desc))
warned[warn_key] = true warned[warn_key] = true
@ -35,9 +30,8 @@ function meta:__newindex(name, value)
declared[name] = true declared[name] = true
end end
-- Ignore mod namespaces -- Ignore mod namespaces
if WARN_INIT and (not core.get_current_modname or if WARN_INIT and name ~= core.get_current_modname() then
name ~= core.get_current_modname()) then core.log("warning", ("Global variable %q created at %s.")
warn(("Global variable %q created at %s.")
:format(name, desc)) :format(name, desc))
end end
rawset(self, name, value) rawset(self, name, value)
@ -48,7 +42,7 @@ function meta:__index(name)
local info = debug.getinfo(2, "Sl") local info = debug.getinfo(2, "Sl")
local warn_key = ("%s\0%d\0%s"):format(info.source, info.currentline, name) 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 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)) :format(name, info.short_src, info.currentline))
warned[warn_key] = true warned[warn_key] = true
end end

@ -127,11 +127,13 @@ function ui.update()
end end
if (active_toplevel_ui_elements > 1) then 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 end
if (active_toplevel_ui_elements == 0) then 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() ui.childlist[ui.default]:show()
formspec = ui.childlist[ui.default]:get_formspec() formspec = ui.childlist[ui.default]:get_formspec()
end end

@ -4,8 +4,7 @@
-- Default material types -- Default material types
-- --
local function digprop_err() local function digprop_err()
core.log("info", debug.traceback()) core.log("deprecated", "The core.digprop_* functions are obsolete and need to be replaced by item groups.")
core.log("info", "WARNING: The core.digprop_* functions are obsolete and need to be replaced by item groups.")
end end
core.digprop_constanttime = digprop_err core.digprop_constanttime = digprop_err
@ -16,12 +15,12 @@ core.digprop_woodlike = digprop_err
core.digprop_leaveslike = digprop_err core.digprop_leaveslike = digprop_err
core.digprop_glasslike = digprop_err core.digprop_glasslike = digprop_err
core.node_metadata_inventory_move_allow_all = function() function core.node_metadata_inventory_move_allow_all()
core.log("info", "WARNING: core.node_metadata_inventory_move_allow_all is obsolete and does nothing.") core.log("deprecated", "core.node_metadata_inventory_move_allow_all is obsolete and does nothing.")
end end
core.add_to_creative_inventory = function(itemstring) function core.add_to_creative_inventory(itemstring)
core.log('info', "WARNING: core.add_to_creative_inventory: This function is deprecated and does nothing.") core.log("deprecated", "core.add_to_creative_inventory: This function is deprecated and does nothing.")
end end
-- --
@ -32,7 +31,7 @@ local envref_deprecation_message_printed = false
setmetatable(core.env, { setmetatable(core.env, {
__index = function(table, key) __index = function(table, key)
if not envref_deprecation_message_printed then 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 envref_deprecation_message_printed = true
end end
local func = core[key] local func = core[key]

@ -221,7 +221,7 @@ function core.register_alias(name, convert_to)
error("Unable to register alias: Name is forbidden: " .. name) error("Unable to register alias: Name is forbidden: " .. name)
end end
if core.registered_items[name] ~= nil then 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) " is already defined: " .. name .. " -> " .. convert_to)
else else
--core.log("Registering alias: " .. name .. " -> " .. convert_to) --core.log("Registering alias: " .. name .. " -> " .. convert_to)

@ -6,7 +6,7 @@
-- --
-- Initialize some very basic things -- Initialize some very basic things
print = core.debug function core.debug(...) core.log(table.concat({...}, "\t")) end
math.randomseed(os.time()) math.randomseed(os.time())
os.setlocale("C", "numeric") os.setlocale("C", "numeric")
minetest = core minetest = core

@ -1774,11 +1774,11 @@ Helper functions
* false: return only file names. * false: return only file names.
### Logging ### Logging
* `minetest.debug(line)` * `minetest.debug(...)`
* Always printed to `stderr` and logfile (`print()` is redirected here) * Equivalent to `minetest.log(table.concat({...}, "\t"))`
* `minetest.log(line)` * `minetest.log([level,] text)`
* `minetest.log(loglevel, line)` * `level` is one of `"none"`, `"error"`, `"warning"`, `"action"`,
* `loglevel` is one of `"error"`, `"action"`, `"info"`, `"verbose"` `"info"`, or `"verbose"`. Default is `"none"`.
### Registration functions ### Registration functions
Call these functions only at load time! Call these functions only at load time!

@ -612,8 +612,9 @@
#remote_media = #remote_media =
# Level of logging to be written to debug.txt: # Level of logging to be written to debug.txt:
# 0 = none, 1 = errors and debug, 2 = action, 3 = info, 4 = verbose. # <nothing> (no logging), none (messages with no level), error,
#debug_log_level = 2 # warning, action, info, or verbose.
#debug_log_level = action
# Maximum number of blocks that can be queued for loading # Maximum number of blocks that can be queued for loading
#emergequeue_limit_total = 256 #emergequeue_limit_total = 256

@ -89,7 +89,7 @@ bool ClientLauncher::run(GameParams &game_params, const Settings &cmd_args)
if (list_video_modes) if (list_video_modes)
return print_video_modes(); return print_video_modes();
if (!init_engine(game_params.log_level)) { if (!init_engine()) {
errorstream << "Could not initialize game engine." << std::endl; errorstream << "Could not initialize game engine." << std::endl;
return false; return false;
} }
@ -321,10 +321,10 @@ void ClientLauncher::init_args(GameParams &game_params, const Settings &cmd_args
|| cmd_args.getFlag("random-input"); || cmd_args.getFlag("random-input");
} }
bool ClientLauncher::init_engine(int log_level) bool ClientLauncher::init_engine()
{ {
receiver = new MyEventReceiver(); receiver = new MyEventReceiver();
create_engine_device(log_level); create_engine_device();
return device != NULL; return device != NULL;
} }
@ -455,7 +455,7 @@ bool ClientLauncher::launch_game(std::string &error_message,
if (game_params.game_spec.isValid() && if (game_params.game_spec.isValid() &&
game_params.game_spec.id != worldspec.gameid) { game_params.game_spec.id != worldspec.gameid) {
errorstream << "WARNING: Overriding gamespec from \"" warningstream << "Overriding gamespec from \""
<< worldspec.gameid << "\" to \"" << worldspec.gameid << "\" to \""
<< game_params.game_spec.id << "\"" << std::endl; << game_params.game_spec.id << "\"" << std::endl;
gamespec = game_params.game_spec; gamespec = game_params.game_spec;
@ -500,20 +500,8 @@ void ClientLauncher::main_menu(MainMenuData *menudata)
smgr->clear(); /* leave scene manager in a clean state */ 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 // Resolution selection
bool fullscreen = g_settings->getBool("fullscreen"); bool fullscreen = g_settings->getBool("fullscreen");
u16 screenW = g_settings->getU16("screenW"); u16 screenW = g_settings->getU16("screenW");
@ -561,10 +549,6 @@ bool ClientLauncher::create_engine_device(int log_level)
device = createDeviceEx(params); device = createDeviceEx(params);
if (device) { 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); porting::initIrrlicht(device);
} }

@ -90,13 +90,13 @@ public:
protected: protected:
void init_args(GameParams &game_params, const Settings &cmd_args); 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, bool launch_game(std::string &error_message, bool reconnect_requested,
GameParams &game_params, const Settings &cmd_args); GameParams &game_params, const Settings &cmd_args);
void main_menu(MainMenuData *menudata); void main_menu(MainMenuData *menudata);
bool create_engine_device(int log_level); bool create_engine_device();
void speed_tests(); void speed_tests();
bool print_video_modes(); bool print_video_modes();

@ -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. 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
*/ */
#ifndef __INPUT_HANDLER_H__ #ifndef INPUT_HANDLER_H
#define __INPUT_HANDLER_H__ #define INPUT_HANDLER_H
#include "irrlichttypes_extrabloated.h" #include "irrlichttypes_extrabloated.h"
@ -86,16 +86,16 @@ public:
} }
} }
} else if (event.EventType == irr::EET_LOG_TEXT_EVENT) { } else if (event.EventType == irr::EET_LOG_TEXT_EVENT) {
static const enum LogMessageLevel irr_loglev_conv[] = { static const LogLevel irr_loglev_conv[] = {
LMT_VERBOSE, // ELL_DEBUG LL_VERBOSE, // ELL_DEBUG
LMT_INFO, // ELL_INFORMATION LL_INFO, // ELL_INFORMATION
LMT_ACTION, // ELL_WARNING LL_WARNING, // ELL_WARNING
LMT_ERROR, // ELL_ERROR LL_ERROR, // ELL_ERROR
LMT_ERROR, // ELL_NONE LL_NONE, // ELL_NONE
}; };
assert(event.LogEvent.Level < ARRLEN(irr_loglev_conv)); assert(event.LogEvent.Level < ARRLEN(irr_loglev_conv));
log_printline(irr_loglev_conv[event.LogEvent.Level], g_logger.log(irr_loglev_conv[event.LogEvent.Level],
std::string("Irrlicht: ") + (const char *)event.LogEvent.Text); std::string("Irrlicht: ") + (const char*) event.LogEvent.Text);
return true; return true;
} }
/* always return false in order to continue processing events */ /* always return false in order to continue processing events */

@ -26,6 +26,7 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include <stdlib.h> #include <stdlib.h>
#include <cstring> #include <cstring>
#include <map> #include <map>
#include <sstream>
#include "threading/mutex.h" #include "threading/mutex.h"
#include "threading/mutex_auto_lock.h" #include "threading/mutex_auto_lock.h"
#include "config.h" #include "config.h"
@ -36,99 +37,6 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "filesys.h" #include "filesys.h"
#endif #endif
/*
Debug output
*/
#define DEBUGSTREAM_COUNT 2
FILE *g_debugstreams[DEBUGSTREAM_COUNT] = {stderr, NULL};
#define DEBUGPRINT(...)\
{\
for(int i=0; i<DEBUGSTREAM_COUNT; i++)\
{\
if(g_debugstreams[i] != NULL){\
fprintf(g_debugstreams[i], __VA_ARGS__);\
fflush(g_debugstreams[i]);\
}\
}\
}
void debugstreams_init(bool disable_stderr, const char *filename)
{
if(disable_stderr)
g_debugstreams[0] = NULL;
else
g_debugstreams[0] = stderr;
if(filename)
g_debugstreams[1] = fopen(filename, "a");
if(g_debugstreams[1])
{
fprintf(g_debugstreams[1], "\n\n-------------\n");
fprintf(g_debugstreams[1], " Separator \n");
fprintf(g_debugstreams[1], "-------------\n\n");
}
}
void debugstreams_deinit()
{
if(g_debugstreams[1] != NULL)
fclose(g_debugstreams[1]);
}
class Debugbuf : public std::streambuf
{
public:
Debugbuf(bool disable_stderr)
{
m_disable_stderr = disable_stderr;
}
int overflow(int c)
{
for(int i=0; i<DEBUGSTREAM_COUNT; i++)
{
if(g_debugstreams[i] == stderr && m_disable_stderr)
continue;
if(g_debugstreams[i] != NULL)
(void)fwrite(&c, 1, 1, g_debugstreams[i]);
//TODO: Is this slow?
fflush(g_debugstreams[i]);
}
return c;
}
std::streamsize xsputn(const char *s, std::streamsize n)
{
#ifdef __ANDROID__
__android_log_print(ANDROID_LOG_VERBOSE, PROJECT_NAME, "%s", s);
#endif
for(int i=0; i<DEBUGSTREAM_COUNT; i++)
{
if(g_debugstreams[i] == stderr && m_disable_stderr)
continue;
if(g_debugstreams[i] != NULL)
(void)fwrite(s, 1, n, g_debugstreams[i]);
//TODO: Is this slow?
fflush(g_debugstreams[i]);
}
return n;
}
private:
bool m_disable_stderr;
};
Debugbuf debugbuf(false);
std::ostream dstream(&debugbuf);
Debugbuf debugbuf_no_stderr(true);
std::ostream dstream_no_stderr(&debugbuf_no_stderr);
Nullstream dummyout;
/* /*
Assert Assert
*/ */
@ -136,15 +44,12 @@ Nullstream dummyout;
void sanity_check_fn(const char *assertion, const char *file, void sanity_check_fn(const char *assertion, const char *file,
unsigned int line, const char *function) unsigned int line, const char *function)
{ {
DEBUGPRINT("\nIn thread %lx:\n" errorstream << std::endl << "In thread " << std::hex
"%s:%u: %s: An engine assumption '%s' failed.\n", << (unsigned long)get_current_thread_id() << ":" << std::endl;
(unsigned long)get_current_thread_id(), errorstream << file << ":" << line << ": " << function
file, line, function, assertion); << ": An engine assumption '" << assertion << "' failed." << std::endl;
debug_stacks_print(); debug_stacks_print_to(errorstream);
if(g_debugstreams[1])
fclose(g_debugstreams[1]);
abort(); abort();
} }
@ -152,15 +57,12 @@ void sanity_check_fn(const char *assertion, const char *file,
void fatal_error_fn(const char *msg, const char *file, void fatal_error_fn(const char *msg, const char *file,
unsigned int line, const char *function) unsigned int line, const char *function)
{ {
DEBUGPRINT("\nIn thread %lx:\n" errorstream << std::endl << "In thread " << std::hex
"%s:%u: %s: A fatal error occurred: %s\n", << (unsigned long)get_current_thread_id() << ":" << std::endl;
(unsigned long)get_current_thread_id(), errorstream << file << ":" << line << ": " << function
file, line, function, msg); << ": A fatal error occured: " << msg << std::endl;
debug_stacks_print(); debug_stacks_print_to(errorstream);
if(g_debugstreams[1])
fclose(g_debugstreams[1]);
abort(); abort();
} }
@ -251,22 +153,7 @@ void debug_stacks_print_to(std::ostream &os)
void debug_stacks_print() void debug_stacks_print()
{ {
MutexAutoLock lock(g_debug_stacks_mutex); debug_stacks_print_to(errorstream);
DEBUGPRINT("Debug stacks:\n");
for(std::map<threadid_t, DebugStack*>::iterator
i = g_debug_stacks.begin();
i != g_debug_stacks.end(); ++i)
{
DebugStack *stack = i->second;
for(int i=0; i<DEBUGSTREAM_COUNT; i++)
{
if(g_debugstreams[i] != NULL)
stack->print(g_debugstreams[i], true);
}
}
} }
DebugStacker::DebugStacker(const char *text) DebugStacker::DebugStacker(const char *text)

@ -24,6 +24,7 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include <exception> #include <exception>
#include <assert.h> #include <assert.h>
#include "gettime.h" #include "gettime.h"
#include "log.h"
#if (defined(WIN32) || defined(_WIN32_WCE)) #if (defined(WIN32) || defined(_WIN32_WCE))
#define WIN32_LEAN_AND_MEAN #define WIN32_LEAN_AND_MEAN
@ -36,9 +37,13 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#endif #endif
#define __NORETURN __declspec(noreturn) #define __NORETURN __declspec(noreturn)
#define __FUNCTION_NAME __FUNCTION__ #define __FUNCTION_NAME __FUNCTION__
#define NORETURN __declspec(noreturn)
#define FUNCTION_NAME __FUNCTION__
#else #else
#define __NORETURN __attribute__ ((__noreturn__)) #define __NORETURN __attribute__ ((__noreturn__))
#define __FUNCTION_NAME __PRETTY_FUNCTION__ #define __FUNCTION_NAME __PRETTY_FUNCTION__
#define NORETURN __attribute__ ((__noreturn__))
#define FUNCTION_NAME __PRETTY_FUNCTION__
#endif #endif
// Whether to catch all std::exceptions. // 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 #define CATCH_UNHANDLED_EXCEPTIONS 0
#endif #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 /* Abort program execution immediately
*/ */
__NORETURN extern void fatal_error_fn( __NORETURN extern void fatal_error_fn(
@ -108,6 +89,8 @@ __NORETURN extern void sanity_check_fn(
void debug_set_exception_handler(); void debug_set_exception_handler();
#define DTIME ""
/* /*
DebugStack DebugStack
*/ */

@ -279,7 +279,7 @@ void set_default_settings(Settings *settings)
settings->setDefault("dedicated_server_step", "0.1"); settings->setDefault("dedicated_server_step", "0.1");
settings->setDefault("ignore_world_load_errors", "false"); settings->setDefault("ignore_world_load_errors", "false");
settings->setDefault("remote_media", ""); 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_total", "256");
settings->setDefault("emergequeue_limit_diskonly", "32"); settings->setDefault("emergequeue_limit_diskonly", "32");
settings->setDefault("emergequeue_limit_generate", "32"); settings->setDefault("emergequeue_limit_generate", "32");

@ -40,7 +40,6 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "guiPasswordChange.h" #include "guiPasswordChange.h"
#include "guiVolumeChange.h" #include "guiVolumeChange.h"
#include "hud.h" #include "hud.h"
#include "logoutputbuffer.h"
#include "mainmenumanager.h" #include "mainmenumanager.h"
#include "mapblock.h" #include "mapblock.h"
#include "nodedef.h" // Needed for determining pointing to nodes #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) ChatBackend &chat_backend, gui::IGUIStaticText *guitext_chat)
{ {
// Add chat log output for errors to be shown in 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 // Get new messages from error log buffer
while (!chat_log_error_buf.empty()) { while (!chat_log_error_buf.empty()) {
@ -2675,7 +2674,7 @@ void Game::processKeyboardInput(VolatileRunFlags *flags,
// Print debug stacks // Print debug stacks
dstream << "-----------------------------------------" dstream << "-----------------------------------------"
<< std::endl; << std::endl;
dstream << DTIME << "Printing debug stacks:" << std::endl; dstream << "Printing debug stacks:" << std::endl;
dstream << "-----------------------------------------" dstream << "-----------------------------------------"
<< std::endl; << std::endl;
debug_stacks_print(); debug_stacks_print();

@ -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. 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
*/ */
#ifndef __GAME_PARAMS_H__ #ifndef GAME_PARAMS_H
#define __GAME_PARAMS_H__ #define GAME_PARAMS_H
#include "irrlichttypes_extrabloated.h" #include "irrlichttypes.h"
struct SubgameSpec;
struct GameParams { struct GameParams {
u16 socket_port; u16 socket_port;
std::string world_path; std::string world_path;
SubgameSpec game_spec; SubgameSpec game_spec;
bool is_dedicated_server; bool is_dedicated_server;
int log_level;
}; };
#endif #endif

@ -19,19 +19,91 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "log.h" #include "log.h"
#include <map>
#include <list>
#include <sstream>
#include <algorithm>
#include "threads.h"
#include "threading/mutex_auto_lock.h" #include "threading/mutex_auto_lock.h"
#include "debug.h" #include "debug.h"
#include "gettime.h" #include "gettime.h"
#include "porting.h" #include "porting.h"
#include "config.h" #include "config.h"
#include "exceptions.h"
#include "util/numeric.h"
#include "log.h"
#include <sstream>
#include <iostream>
#include <algorithm>
#include <cerrno>
#include <cstring>
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 // Connection
std::ostream *dout_con_ptr = &dummyout; std::ostream *dout_con_ptr = &null_stream;
std::ostream *derr_con_ptr = &verbosestream; std::ostream *derr_con_ptr = &verbosestream;
// Server // Server
@ -44,170 +116,211 @@ std::ostream *dout_client_ptr = &infostream;
std::ostream *derr_client_ptr = &errorstream; std::ostream *derr_client_ptr = &errorstream;
#endif #endif
#ifdef __ANDROID__ std::ostream rawstream(&raw_buf);
unsigned int android_log_level_mapping[] = { std::ostream dstream(&none_buf);
/* LMT_ERROR */ ANDROID_LOG_ERROR, std::ostream errorstream(&error_buf);
/* LMT_ACTION */ ANDROID_LOG_WARN, std::ostream warningstream(&warning_buf);
/* LMT_INFO */ ANDROID_LOG_INFO, std::ostream actionstream(&action_buf);
/* LMT_VERBOSE */ ANDROID_LOG_VERBOSE 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<ILogOutput *>::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 assert(lev < LL_MAX && lev >= 0);
assert(ARRLEN(names) == LL_MAX);
std::vector<ILogOutput*> log_outputs[LMT_NUM_VALUES]; return names[lev];
std::map<threadid_t, std::string> log_thread_names;
Mutex log_thread_name_mutex;
void log_add_output(ILogOutput *out, enum LogMessageLevel lev)
{
log_outputs[lev].push_back(out);
} }
void log_add_output_maxlev(ILogOutput *out, enum LogMessageLevel lev) const std::string Logger::getThreadName()
{ {
for(int i=0; i<=lev; i++) std::map<threadid_t, std::string>::const_iterator it;
log_outputs[i].push_back(out);
}
void log_add_output_all_levs(ILogOutput *out)
{
for(int i=0; i<LMT_NUM_VALUES; i++)
log_outputs[i].push_back(out);
}
void log_remove_output(ILogOutput *out)
{
for(int i=0; i<LMT_NUM_VALUES; i++){
std::vector<ILogOutput*>::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<ILogOutput *>::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(); 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(); if (m_silenced_levels[lev])
MutexAutoLock lock(log_thread_name_mutex); return;
log_thread_names.erase(id); const std::string thread_name = getThreadName();
} const std::string label = getLevelLabel(lev);
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<threadid_t, std::string>::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);
std::ostringstream os(std::ios_base::binary); std::ostringstream os(std::ios_base::binary);
os << getTimestamp() << ": " << levelname << "["<<threadname<<"]: " << text; os << getTimestamp() << ": " << label << "[" << thread_name << "]: " << text;
for(std::vector<ILogOutput*>::iterator i = log_outputs[lev].begin(); logToSystem(lev, text);
i != log_outputs[lev].end(); ++i) { logToOutputs(lev, os.str());
ILogOutput *out = *i; }
if (out->silence)
continue;
out->printLog(os.str()); void Logger::logRaw(LogLevel lev, const std::string &text)
out->printLog(os.str(), lev); {
out->printLog(lev, 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: logger.log(level, buffer);
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<n; i++)
bufchar(s[i]);
return n;
}
void printbuf()
{
log_printline(m_lev, m_buf);
#ifdef __ANDROID__
__android_log_print(android_log_level_mapping[m_lev], PROJECT_NAME, "%s", m_buf.c_str());
#endif
}
void bufchar(char c)
{
if(c == '\n' || c == '\r'){
if(m_buf != "")
printbuf();
m_buf = "";
return;
}
m_buf += c;
}
private:
enum LogMessageLevel m_lev;
std::string m_buf;
};
Logbuf errorbuf(LMT_ERROR);
Logbuf actionbuf(LMT_ACTION);
Logbuf infobuf(LMT_INFO);
Logbuf verbosebuf(LMT_VERBOSE);
std::ostream errorstream(&errorbuf);
std::ostream actionstream(&actionbuf);
std::ostream infostream(&infobuf);
std::ostream verbosestream(&verbosebuf);
bool log_trace_level_enabled = false;
void RawLogBuffer::flush(const std::string &buffer)
{
g_logger.logRaw(LL_NONE, buffer);
}

194
src/log.h

@ -20,83 +20,177 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#ifndef LOG_HEADER #ifndef LOG_HEADER
#define LOG_HEADER #define LOG_HEADER
#include <map>
#include <queue>
#include <string> #include <string>
#include <fstream>
#include "threads.h"
/* class ILogOutput;
Use this for logging everything.
If you need to explicitly print something, use dstream or cout or cerr. enum LogLevel {
*/ LL_NONE, // Special level that is always printed
LL_ERROR,
enum LogMessageLevel { LL_WARNING,
LMT_ERROR, /* Something failed ("invalid map data on disk, block (2,2,1)") */ LL_ACTION, // In-game actions
LMT_ACTION, /* In-game actions ("celeron55 placed block at (12,4,-5)") */ LL_INFO,
LMT_INFO, /* More deep info ("saving map on disk (only_modified=true)") */ LL_VERBOSE,
LMT_VERBOSE, /* Flood-style ("loaded block (2,2,2) from disk") */ LL_MAX,
LMT_NUM_VALUES,
}; };
class ILogOutput class Logger {
{
public: public:
ILogOutput() : void addOutput(ILogOutput *out);
silence(false) 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 */ void registerThread(const std::string &name);
virtual void printLog(const std::string &line){}; void deregisterThread();
/* 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){};
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<ILogOutput *> 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<threadid_t, std::string> m_thread_names;
mutable Mutex m_mutex;
bool m_trace_enabled;
}; };
void log_add_output(ILogOutput *out, enum LogMessageLevel lev); class ILogOutput {
void log_add_output_maxlev(ILogOutput *out, enum LogMessageLevel lev); public:
void log_add_output_all_levs(ILogOutput *out); virtual void log(const std::string &line) = 0;
void log_remove_output(ILogOutput *out); };
void log_set_lev_silence(enum LogMessageLevel lev, bool silence);
void log_register_thread(const std::string &name); class StreamLogOutput : public ILogOutput {
void log_deregister_thread(); 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, ...)\ private:
{\ std::ostream &stream;
char buf[10000];\ };
snprintf(buf, 10000, __VA_ARGS__);\
log_printline(lev, buf);\
}
extern std::ostream errorstream; class FileLogOutput : public ILogOutput {
extern std::ostream actionstream; public:
extern std::ostream infostream; void open(const std::string &filename);
extern std::ostream verbosestream;
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; } private:
#define TRACEDO(x){ if(log_trace_level_enabled){ x ;} } 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<std::string> 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 *dout_con_ptr;
extern std::ostream *derr_con_ptr; extern std::ostream *derr_con_ptr;
extern std::ostream *dout_server_ptr; extern std::ostream *dout_server_ptr;
extern std::ostream *derr_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 dout_con (*dout_con_ptr)
#define derr_con (*derr_con_ptr) #define derr_con (*derr_con_ptr)
#define dout_server (*dout_server_ptr) #define dout_server (*dout_server_ptr)
#define derr_server (*derr_server_ptr) #define derr_server (*derr_server_ptr)
#ifndef SERVER #ifndef SERVER
extern std::ostream *dout_client_ptr; #define dout_client (*dout_client_ptr)
extern std::ostream *derr_client_ptr; #define derr_client (*derr_client_ptr)
#define dout_client (*dout_client_ptr)
#define derr_client (*derr_client_ptr)
#endif #endif
#endif
#endif

@ -1,58 +0,0 @@
/*
Minetest
Copyright (C) 2013 celeron55, Perttu Ahola <celeron55@gmail.com>
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 <queue>
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<std::string> m_buf;
};
#endif

@ -80,10 +80,10 @@ static void list_game_ids();
static void list_worlds(); static void list_worlds();
static void setup_log_params(const Settings &cmd_args); static void setup_log_params(const Settings &cmd_args);
static bool create_userdata_path(); 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 void startup_message();
static bool read_config_file(const Settings &cmd_args); 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 bool game_configure(GameParams *game_params, const Settings &cmd_args);
static void game_configure_port(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 #endif
class StderrLogOutput: public ILogOutput FileLogOutput file_log_output;
{
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;
static OptionList allowed_options; static OptionList allowed_options;
@ -150,10 +132,8 @@ int main(int argc, char *argv[])
debug_set_exception_handler(); debug_set_exception_handler();
log_add_output_maxlev(&main_stderr_log_out, LMT_ACTION); g_logger.registerThread("Main");
log_add_output_all_levs(&main_dstream_no_stderr_log_out); g_logger.addOutputMaxLevel(&stderr_output, LL_ACTION);
log_register_thread("Main");
Settings cmd_args; Settings cmd_args;
bool cmd_args_ok = get_cmdline_opts(argc, argv, &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 // Initialize debug stacks
debug_stacks_init(); DSTACK(FUNCTION_NAME);
DSTACK(__FUNCTION_NAME);
// Debug handler // Debug handler
BEGIN_DEBUG_EXCEPTION_HANDLER BEGIN_DEBUG_EXCEPTION_HANDLER
@ -198,8 +177,7 @@ int main(int argc, char *argv[])
return 0; return 0;
} }
GameParams game_params; if (!init_common(cmd_args, argc, argv))
if (!init_common(&game_params.log_level, cmd_args, argc, argv))
return 1; return 1;
#ifndef __ANDROID__ #ifndef __ANDROID__
@ -210,6 +188,7 @@ int main(int argc, char *argv[])
} }
#endif #endif
GameParams game_params;
#ifdef SERVER #ifdef SERVER
game_params.is_dedicated_server = true; game_params.is_dedicated_server = true;
#else #else
@ -219,7 +198,7 @@ int main(int argc, char *argv[])
if (!game_configure(&game_params, cmd_args)) if (!game_configure(&game_params, cmd_args))
return 1; return 1;
sanity_check(game_params.world_path != ""); sanity_check(!game_params.world_path.empty());
infostream << "Using commanded world path [" infostream << "Using commanded world path ["
<< game_params.world_path << "]" << std::endl; << game_params.world_path << "]" << std::endl;
@ -247,7 +226,7 @@ int main(int argc, char *argv[])
// Stop httpfetch thread (if started) // Stop httpfetch thread (if started)
httpfetch_cleanup(); httpfetch_cleanup();
END_DEBUG_EXCEPTION_HANDLER(errorstream) END_DEBUG_EXCEPTION_HANDLER(errorstream);
return retval; return retval;
} }
@ -403,26 +382,26 @@ static void setup_log_params(const Settings &cmd_args)
{ {
// Quiet mode, print errors only // Quiet mode, print errors only
if (cmd_args.getFlag("quiet")) { if (cmd_args.getFlag("quiet")) {
log_remove_output(&main_stderr_log_out); g_logger.removeOutput(&stderr_output);
log_add_output_maxlev(&main_stderr_log_out, LMT_ERROR); g_logger.addOutputMaxLevel(&stderr_output, LL_ERROR);
} }
// If trace is enabled, enable logging of certain things // If trace is enabled, enable logging of certain things
if (cmd_args.getFlag("trace")) { if (cmd_args.getFlag("trace")) {
dstream << _("Enabling trace level debug output") << std::endl; dstream << _("Enabling trace level debug output") << std::endl;
log_trace_level_enabled = true; g_logger.setTraceEnabled(true);
dout_con_ptr = &verbosestream; // this is somewhat old crap dout_con_ptr = &verbosestream; // This is somewhat old
socket_enable_debug_output = true; // socket doesn't use log.h socket_enable_debug_output = true; // Sockets doesn't use log.h
} }
// In certain cases, output info level on stderr // In certain cases, output info level on stderr
if (cmd_args.getFlag("info") || cmd_args.getFlag("verbose") || if (cmd_args.getFlag("info") || cmd_args.getFlag("verbose") ||
cmd_args.getFlag("trace") || cmd_args.getFlag("speedtests")) 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 // In certain cases, output verbose level on stderr
if (cmd_args.getFlag("verbose") || cmd_args.getFlag("trace")) 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() static bool create_userdata_path()
@ -450,7 +429,7 @@ static bool create_userdata_path()
return success; 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(); startup_message();
set_default_settings(g_settings); 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)) if (!read_config_file(cmd_args))
return false; return false;
init_debug_streams(log_level, cmd_args); init_log_streams(cmd_args);
// Initialize random seed // Initialize random seed
srand(time(0)); srand(time(0));
@ -533,38 +512,47 @@ static bool read_config_file(const Settings &cmd_args)
return true; 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 #if RUN_IN_PLACE
std::string logfile = DEBUGFILE; std::string log_filename = DEBUGFILE;
#else #else
std::string logfile = porting::path_user + DIR_DELIM + DEBUGFILE; std::string log_filename = porting::path_user + DIR_DELIM + DEBUGFILE;
#endif #endif
if (cmd_args.exists("logfile")) 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); g_logger.removeOutput(&file_log_output);
*log_level = g_settings->getS32("debug_log_level"); std::string conf_loglev = g_settings->get("debug_log_level");
if (*log_level == 0) //no logging // Old integer format
logfile = ""; if (std::isdigit(conf_loglev[0])) {
if (*log_level < 0) { warningstream << "Deprecated use of debug_log_level with an "
dstream << "WARNING: Supplied debug_log_level < 0; Using 0" << std::endl; "integer value; please update your configuration." << std::endl;
*log_level = 0; static const char *lev_name[] =
} else if (*log_level > LMT_NUM_VALUES) { {"", "error", "action", "info", "verbose"};
dstream << "WARNING: Supplied debug_log_level > " << LMT_NUM_VALUES int lev_i = atoi(conf_loglev.c_str());
<< "; Using " << LMT_NUM_VALUES << std::endl; if (lev_i < 0 || lev_i >= (int)ARRLEN(lev_name)) {
*log_level = LMT_NUM_VALUES; 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, if (conf_loglev.empty()) // No logging
(LogMessageLevel)(*log_level - 1)); 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) 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; << world_path << "]" << std::endl;
// If there are multiple worlds, list them // If there are multiple worlds, list them
} else if (worldspecs.size() > 1 && game_params->is_dedicated_server) { } else if (worldspecs.size() > 1 && game_params->is_dedicated_server) {
dstream << _("Multiple worlds are available.") << std::endl; std::cerr << _("Multiple worlds are available.") << std::endl;
dstream << _("Please select one using --worldname <name>" std::cerr << _("Please select one using --worldname <name>"
" or --world <path>") << std::endl; " or --world <path>") << std::endl;
print_worldspecs(worldspecs, dstream); print_worldspecs(worldspecs, std::cerr);
return false; return false;
// If there are no worlds, automatically create a new one // If there are no worlds, automatically create a new one
} else { } else {
@ -774,7 +762,7 @@ static bool determine_subgame(GameParams *game_params)
if (game_params->game_spec.isValid()) { if (game_params->game_spec.isValid()) {
gamespec = game_params->game_spec; gamespec = game_params->game_spec;
if (game_params->game_spec.id != world_gameid) { if (game_params->game_spec.id != world_gameid) {
errorstream << "WARNING: Using commanded gameid [" warningstream << "Using commanded gameid ["
<< gamespec.id << "]" << " instead of world gameid [" << gamespec.id << "]" << " instead of world gameid ["
<< world_gameid << "]" << std::endl; << 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); return migrate_database(game_params, cmd_args);
// Create server // Create server
Server server(game_params.world_path, Server server(game_params.world_path, game_params.game_spec, false,
game_params.game_spec, false, bind_addr.isIPv6()); bind_addr.isIPv6());
server.start(bind_addr); server.start(bind_addr);
// Run server // Run server

@ -18,8 +18,6 @@ with this program; if not, write to the Free Software Foundation, Inc.,
*/ */
#include "minimap.h" #include "minimap.h"
#include <math.h>
#include "logoutputbuffer.h"
#include "threading/mutex_auto_lock.h" #include "threading/mutex_auto_lock.h"
#include "threading/semaphore.h" #include "threading/semaphore.h"
#include "clientmap.h" #include "clientmap.h"
@ -28,6 +26,7 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "porting.h" #include "porting.h"
#include "util/numeric.h" #include "util/numeric.h"
#include "util/string.h" #include "util/string.h"
#include <math.h>
//// ////

@ -26,7 +26,6 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "json/json.h" #include "json/json.h"
#include "cpp_api/s_security.h" #include "cpp_api/s_security.h"
#include "areastore.h" #include "areastore.h"
#include "debug.h"
#include "porting.h" #include "porting.h"
#include "log.h" #include "log.h"
#include "tool.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 "util/auth.h"
#include <algorithm> #include <algorithm>
// 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) // log([level,] text)
// Writes a line to the logger. // Writes a line to the logger.
// The one-argument version logs to infostream. // The one-argument version logs to infostream.
@ -72,26 +42,24 @@ int ModApiUtil::l_log(lua_State *L)
{ {
NO_MAP_LOCK_REQUIRED; NO_MAP_LOCK_REQUIRED;
std::string text; std::string text;
LogMessageLevel level = LMT_INFO; LogLevel level = LL_NONE;
if (lua_isnone(L, 2)) { if (lua_isnone(L, 2)) {
text = lua_tostring(L, 1); text = luaL_checkstring(L, 1);
} } else {
else { std::string name = luaL_checkstring(L, 1);
std::string levelname = luaL_checkstring(L, 1);
text = luaL_checkstring(L, 2); text = luaL_checkstring(L, 2);
if(levelname == "error") if (name == "deprecated") {
level = LMT_ERROR; log_deprecated(L, text);
else if(levelname == "action")
level = LMT_ACTION;
else if(levelname == "verbose")
level = LMT_VERBOSE;
else if (levelname == "deprecated") {
log_deprecated(L,text);
return 0; 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; return 0;
} }
@ -390,7 +358,6 @@ int ModApiUtil::l_request_insecure_environment(lua_State *L)
void ModApiUtil::Initialize(lua_State *L, int top) void ModApiUtil::Initialize(lua_State *L, int top)
{ {
API_FCT(debug);
API_FCT(log); API_FCT(log);
API_FCT(setting_set); API_FCT(setting_set);
@ -422,7 +389,6 @@ void ModApiUtil::Initialize(lua_State *L, int top)
void ModApiUtil::InitializeAsync(AsyncEngine& engine) void ModApiUtil::InitializeAsync(AsyncEngine& engine)
{ {
ASYNC_API_FCT(debug);
ASYNC_API_FCT(log); ASYNC_API_FCT(log);
//ASYNC_API_FCT(setting_set); //ASYNC_API_FCT(setting_set);

@ -35,10 +35,6 @@ private:
GUIEngine instance should be in here. GUIEngine instance should be in here.
*/ */
// debug(text)
// Writes a line to dstream
static int l_debug(lua_State *L);
// log([level,] text) // log([level,] text)
// Writes a line to the logger. // Writes a line to the logger.
// The one-argument version logs to infostream. // The one-argument version logs to infostream.

@ -222,11 +222,11 @@ void *Thread::theThread(void *param)
th->running = true; th->running = true;
th->setName(); th->setName();
log_register_thread(th->name); g_logger.registerThread(th->name);
th->retval = th->run(); th->retval = th->run();
log_deregister_thread(); g_logger.deregisterThread();
th->running = false; th->running = false;
#if __cplusplus < 201103L #if __cplusplus < 201103L

@ -19,7 +19,6 @@ with this program; if not, write to the Free Software Foundation, Inc.,
#include "test.h" #include "test.h"
#include "debug.h"
#include "log.h" #include "log.h"
#include "nodedef.h" #include "nodedef.h"
#include "itemdef.h" #include "itemdef.h"
@ -223,7 +222,7 @@ void run_tests()
u32 t1 = porting::getTime(PRECISION_MILLI); u32 t1 = porting::getTime(PRECISION_MILLI);
TestGameDef gamedef; TestGameDef gamedef;
log_set_lev_silence(LMT_ERROR, true); g_logger.setLevelSilenced(LL_ERROR, true);
u32 num_modules_failed = 0; u32 num_modules_failed = 0;
u32 num_total_tests_failed = 0; u32 num_total_tests_failed = 0;
@ -239,11 +238,11 @@ void run_tests()
u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; 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"; const char *overall_status = (num_modules_failed == 0) ? "PASSED" : "FAILED";
dstream rawstream
<< "++++++++++++++++++++++++++++++++++++++++" << "++++++++++++++++++++++++++++++++++++++++"
<< "++++++++++++++++++++++++++++++++++++++++" << std::endl << "++++++++++++++++++++++++++++++++++++++++" << std::endl
<< "Unit Test Results: " << overall_status << std::endl << "Unit Test Results: " << overall_status << std::endl
@ -264,14 +263,14 @@ void run_tests()
bool TestBase::testModule(IGameDef *gamedef) bool TestBase::testModule(IGameDef *gamedef)
{ {
dstream << "======== Testing module " << getName() << std::endl; rawstream << "======== Testing module " << getName() << std::endl;
u32 t1 = porting::getTime(PRECISION_MILLI); u32 t1 = porting::getTime(PRECISION_MILLI);
runTests(gamedef); runTests(gamedef);
u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; u32 tdiff = porting::getTime(PRECISION_MILLI) - t1;
dstream << "======== Module " << getName() << " " rawstream << "======== Module " << getName() << " "
<< (num_tests_failed ? "failed" : "passed") << " (" << num_tests_failed << (num_tests_failed ? "failed" : "passed") << " (" << num_tests_failed
<< " failures / " << num_tests_run << " tests) - " << tdiff << " failures / " << num_tests_run << " tests) - " << tdiff
<< "ms" << std::endl; << "ms" << std::endl;

@ -32,60 +32,61 @@ class TestFailedException : public std::exception {
}; };
// Runs a unit test and reports results // Runs a unit test and reports results
#define TEST(fxn, ...) do { \ #define TEST(fxn, ...) do { \
u32 t1 = porting::getTime(PRECISION_MILLI); \ u32 t1 = porting::getTime(PRECISION_MILLI); \
try { \ try { \
fxn(__VA_ARGS__); \ fxn(__VA_ARGS__); \
dstream << "[PASS] "; \ rawstream << "[PASS] "; \
} catch (TestFailedException &e) { \ } catch (TestFailedException &e) { \
dstream << "[FAIL] "; \ rawstream << "[FAIL] "; \
num_tests_failed++; \ num_tests_failed++; \
} catch (std::exception &e) { \ } catch (std::exception &e) { \
dstream << "Caught unhandled exception: " << e.what() << std::endl; \ rawstream << "Caught unhandled exception: " << e.what() << std::endl; \
dstream << "[FAIL] "; \ rawstream << "[FAIL] "; \
num_tests_failed++; \ num_tests_failed++; \
} \ } \
num_tests_run++; \ num_tests_run++; \
u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; \ u32 tdiff = porting::getTime(PRECISION_MILLI) - t1; \
dstream << #fxn << " - " << tdiff << "ms" << std::endl; \ rawstream << #fxn << " - " << tdiff << "ms" << std::endl; \
} while (0) } while (0)
// Asserts the specified condition is true, or fails the current unit test // Asserts the specified condition is true, or fails the current unit test
#define UASSERT(x) do { \ #define UASSERT(x) do { \
if (!(x)) { \ if (!(x)) { \
dstream << "Test assertion failed: " #x << std::endl \ rawstream << "Test assertion failed: " #x << std::endl \
<< " at " << fs::GetFilenameFromPath(__FILE__) \ << " at " << fs::GetFilenameFromPath(__FILE__) \
<< ":" << __LINE__ << std::endl; \ << ":" << __LINE__ << std::endl; \
throw TestFailedException(); \ throw TestFailedException(); \
} \ } \
} while (0) } while (0)
// Asserts the specified condition is true, or fails the current unit test // Asserts the specified condition is true, or fails the current unit test
// and prints the format specifier fmt // and prints the format specifier fmt
#define UTEST(x, fmt, ...) do { \ #define UTEST(x, fmt, ...) do { \
if (!(x)) { \ if (!(x)) { \
char utest_buf[1024]; \ char utest_buf[1024]; \
snprintf(utest_buf, sizeof(utest_buf), fmt, __VA_ARGS__); \ snprintf(utest_buf, sizeof(utest_buf), fmt, __VA_ARGS__); \
dstream << "Test assertion failed: " << utest_buf << std::endl \ rawstream << "Test assertion failed: " << utest_buf << std::endl \
<< " at " << fs::GetFilenameFromPath(__FILE__) \ << " at " << fs::GetFilenameFromPath(__FILE__) \
<< ":" << __LINE__ << std::endl; \ << ":" << __LINE__ << std::endl; \
throw TestFailedException(); \ throw TestFailedException(); \
} \ } \
} while (0) } while (0)
// Asserts the comparison specified by CMP is true, or fails the current unit test // Asserts the comparison specified by CMP is true, or fails the current unit test
#define UASSERTCMP(T, CMP, actual, expected) do { \ #define UASSERTCMP(T, CMP, actual, expected) do { \
T a = (actual); \ T a = (actual); \
T e = (expected); \ T e = (expected); \
if (!(a CMP e)) { \ if (!(a CMP e)) { \
dstream << "Test assertion failed: " << #actual << " " << #CMP << " " \ rawstream \
<< #expected << std::endl \ << "Test assertion failed: " << #actual << " " << #CMP << " " \
<< " at " << fs::GetFilenameFromPath(__FILE__) << ":" \ << #expected << std::endl \
<< __LINE__ << std::endl \ << " at " << fs::GetFilenameFromPath(__FILE__) << ":" \
<< " actual: " << a << std::endl << " expected: " \ << __LINE__ << std::endl \
<< e << std::endl; \ << " actual: " << a << std::endl << " expected: " \
throw TestFailedException(); \ << e << std::endl; \
} \ throw TestFailedException(); \
} \
} while (0) } while (0)
#define UASSERTEQ(T, actual, expected) UASSERTCMP(T, ==, actual, expected) #define UASSERTEQ(T, actual, expected) UASSERTCMP(T, ==, actual, expected)