diff --git a/librz/bin/dwarf/unit.c b/librz/bin/dwarf/unit.c index ae43b22735..42de760ab3 100644 --- a/librz/bin/dwarf/unit.c +++ b/librz/bin/dwarf/unit.c @@ -83,7 +83,7 @@ static bool CU_attrs_parse( RzBinDwarfCompUnit *cu, RzBinDwarfAbbrevDecl *abbrev_decl) { - RZ_LOG_SILLY("0x%" PFMT64x ":\t%s%s [%" PFMT64d "] %s\n", + RZ_LOG_DEBUG("0x%" PFMT64x ":\t%s%s [%" PFMT64d "] %s\n", die->offset, rz_str_indent(die->depth), rz_bin_dwarf_tag(die->tag), die->abbrev_code, rz_bin_dwarf_children(die->has_children)); RzBinDwarfAttrSpec *spec = NULL; @@ -195,7 +195,7 @@ static bool CU_dies_parse( }; // there can be "null" entries that have abbr_code == 0 if (!abbrev_code) { - RZ_LOG_SILLY("0x%" PFMT64x ":\t%sNULL\n", offset, rz_str_indent(die.depth)); + RZ_LOG_DEBUG("0x%" PFMT64x ":\t%sNULL\n", offset, rz_str_indent(die.depth)); rz_vector_push(&unit->dies, &die); depth--; if (depth <= 0) { diff --git a/librz/core/cconfig.c b/librz/core/cconfig.c index 4653e248c0..5d63544e2f 100644 --- a/librz/core/cconfig.c +++ b/librz/core/cconfig.c @@ -2872,29 +2872,28 @@ static bool cb_log_config_level(void *coreptr, void *nodeptr) { return true; } -static bool cb_log_config_traplevel(void *coreptr, void *nodeptr) { +#if RZ_BUILD_DEBUG +static bool cb_log_config_abortlevel(void *coreptr, void *nodeptr) { RzConfigNode *node = (RzConfigNode *)nodeptr; - rz_log_set_traplevel(node->i_value); + rz_log_set_abortlevel(node->i_value); return true; } +#endif /* RZ_BUILD_DEBUG */ static bool cb_log_config_file(void *coreptr, void *nodeptr) { RzConfigNode *node = (RzConfigNode *)nodeptr; - const char *value = node->value; - rz_log_set_file(value); - return true; + return rz_log_set_file(node->value); } -static bool cb_log_config_srcinfo(void *coreptr, void *nodeptr) { +static bool cb_log_config_show_sources(void *coreptr, void *nodeptr) { RzConfigNode *node = (RzConfigNode *)nodeptr; const char *value = node->value; - switch (value[0]) { - case 't': - case 'T': - rz_log_set_srcinfo(true); - break; - default: - rz_log_set_srcinfo(false); + if (rz_str_is_true(value)) { + rz_log_set_show_sources(true); + } else if (rz_str_is_false(value)) { + rz_log_set_show_sources(false); + } else { + return false; } return true; } @@ -2902,13 +2901,12 @@ static bool cb_log_config_srcinfo(void *coreptr, void *nodeptr) { static bool cb_log_config_colors(void *coreptr, void *nodeptr) { RzConfigNode *node = (RzConfigNode *)nodeptr; const char *value = node->value; - switch (value[0]) { - case 't': - case 'T': + if (rz_str_is_true(value)) { rz_log_set_colors(true); - break; - default: + } else if (rz_str_is_false(value)) { rz_log_set_colors(false); + } else { + return false; } return true; } @@ -3338,21 +3336,27 @@ RZ_API int rz_core_config_init(RzCore *core) { // RZ_LOGLEVEL / log.level p = rz_sys_getenv("RZ_LOGLEVEL"); SETICB("log.level", p ? atoi(p) : RZ_DEFAULT_LOGLVL, cb_log_config_level, "Target log level/severity" - " (0:SILLY, 1:DEBUG, 2:VERBOSE, 3:INFO, 4:WARN, 5:ERROR, 6:FATAL)"); + " (0:DEBUG, 1:VERBOSE, 2:INFO, 3:WARN, 4:ERROR, 5:FATAL)"); free(p); - // RZ_LOGTRAP_LEVEL / log.traplevel - p = rz_sys_getenv("RZ_LOGTRAPLEVEL"); - SETICB("log.traplevel", p ? atoi(p) : RZ_LOGLVL_FATAL, cb_log_config_traplevel, "Log level for trapping rizin when hit" - " (0:SILLY, 1:VERBOSE, 2:DEBUG, 3:INFO, 4:WARN, 5:ERROR, 6:FATAL)"); + +#if RZ_BUILD_DEBUG + // RZ_ABORTLEVEL / log.abortlevel + p = rz_sys_getenv("RZ_ABORTLEVEL"); + SETICB("log.abortlevel", p ? atoi(p) : RZ_DEFAULT_LOGLVL_ABORT, cb_log_config_abortlevel, "Target log level/severity when to abort." + " (0:DEBUG, 1:VERBOSE, 2:INFO, 3:WARN, 4:ERROR, 5:FATAL)"); free(p); +#endif /* RZ_BUILD_DEBUG */ + // RZ_LOGFILE / log.file p = rz_sys_getenv("RZ_LOGFILE"); SETCB("log.file", p ? p : "", cb_log_config_file, "Logging output filename / path"); free(p); - // RZ_LOGSRCINFO / log.srcinfo - p = rz_sys_getenv("RZ_LOGSRCINFO"); - SETCB("log.srcinfo", p ? p : "false", cb_log_config_srcinfo, "Should the log output contain src info (filename:lineno)"); + + // RZ_LOGSHOWSOURCES / log.show.sources + p = rz_sys_getenv("RZ_LOGSHOWSOURCES"); + SETCB("log.show.sources", p ? p : "false", cb_log_config_show_sources, "Should the log output contain src info (filename:lineno)"); free(p); + // RZ_LOGCOLORS / log.colors p = rz_sys_getenv("RZ_LOGCOLORS"); SETCB("log.colors", p ? p : "false", cb_log_config_colors, "Should the log output use colors (TODO)"); diff --git a/librz/include/rz_util/rz_log.h b/librz/include/rz_util/rz_log.h index b3264c07a0..30fc95977d 100644 --- a/librz/include/rz_util/rz_log.h +++ b/librz/include/rz_util/rz_log.h @@ -14,13 +14,14 @@ #endif typedef enum rz_log_level { - RZ_LOGLVL_SILLY = 0, - RZ_LOGLVL_DEBUG = 1, - RZ_LOGLVL_VERBOSE = 2, - RZ_LOGLVL_INFO = 3, - RZ_LOGLVL_WARN = 4, - RZ_LOGLVL_ERROR = 5, - RZ_LOGLVL_FATAL = 6, // This will call rz_sys_breakpoint() and trap the process for debugging! + RZ_LOGLVL_DEBUG = 0, + RZ_LOGLVL_VERBOSE, + RZ_LOGLVL_INFO, + RZ_LOGLVL_WARN, + RZ_LOGLVL_ERROR, + RZ_LOGLVL_FATAL, ///< This will call rz_sys_breakpoint() and trap the process for debugging! + /* other flags */ + RZ_LOGLVL_SIZE, RZ_LOGLVL_NONE = 0xFF } RzLogLevel; @@ -40,12 +41,10 @@ typedef void (*RzLogCallback)(const char *output, const char *funcname, const ch __LINE__, lvl, tag, fmtstr, ##__VA_ARGS__); #if RZ_BUILD_DEBUG -#define RZ_LOG_SILLY(fmtstr, ...) rz_log(MACRO_LOG_FUNC, __FILE__, \ - __LINE__, RZ_LOGLVL_SILLY, NULL, fmtstr, ##__VA_ARGS__); +#define RZ_DEFAULT_LOGLVL_ABORT RZ_LOGLVL_FATAL #define RZ_LOG_DEBUG(fmtstr, ...) rz_log(MACRO_LOG_FUNC, __FILE__, \ __LINE__, RZ_LOGLVL_DEBUG, NULL, fmtstr, ##__VA_ARGS__); #else -#define RZ_LOG_SILLY(fmtstr, ...) #define RZ_LOG_DEBUG(fmtstr, ...) #endif @@ -66,14 +65,14 @@ extern "C" { // Called by rz_core to set the configuration variables RZ_API void rz_log_set_level(RzLogLevel level); -RZ_API void rz_log_set_file(const char *filename); -RZ_API void rz_log_set_srcinfo(bool show_info); +RZ_API void rz_log_set_abortlevel(RzLogLevel level); +RZ_API bool rz_log_set_file(RZ_NULLABLE const char *filename); +RZ_API void rz_log_set_show_sources(bool show_sources); RZ_API void rz_log_set_colors(bool show_colors); -RZ_API void rz_log_set_traplevel(RzLogLevel level); // Functions for adding log callbacks -RZ_API void rz_log_add_callback(RzLogCallback cbfunc); -RZ_API void rz_log_del_callback(RzLogCallback cbfunc); +RZ_API void rz_log_add_callback(RZ_NULLABLE RzLogCallback cbfunc); +RZ_API void rz_log_del_callback(RZ_NULLABLE RzLogCallback cbfunc); // TODO: rz_log_get_callbacks() /* Define rz_log as weak so it can be 'overwritten' externally diff --git a/librz/util/log.c b/librz/util/log.c index 2b2209acaa..d4c88a16d0 100644 --- a/librz/util/log.c +++ b/librz/util/log.c @@ -1,137 +1,256 @@ +// SPDX-FileCopyrightText: 2024 RizinOrg // SPDX-FileCopyrightText: 2007-2018 pancake // SPDX-FileCopyrightText: 2007-2018 ret2libc // SPDX-License-Identifier: LGPL-3.0-only -#define LOG_CONFIGSTR_SIZE 512 -#define LOG_OUTPUTBUF_SIZE 512 - -#include +#include +#include +#include #include -// TODO: Use thread-local storage to make these variables thread-safe -static RzList *log_cbs = NULL; // Functions to call when outputting log string -static int cfg_loglvl = RZ_LOGLVL_WARN; // Log level output -static int cfg_logtraplvl = RZ_LOGLVL_FATAL; // Log trap level -static bool cfg_logsrcinfo = false; // Print out debug source info with the output -static bool cfg_logcolors = false; // Output colored log text based on level -static char cfg_logfile[LOG_CONFIGSTR_SIZE] = ""; // Output text to filename -static const char *level_tags[] = { // Log level to tag string lookup array - [RZ_LOGLVL_SILLY] = "SILLY", +typedef struct log_config_s { + RzList /**/ *callbacks; + RzLogLevel level; +#if RZ_BUILD_DEBUG + RzLogLevel abortlevel; +#endif + bool show_sources; + FILE *file; + const char **tags; + RzThreadLock *lock; +} log_config_t; + +///< Log level to tag string lookup array +static const char *level_tags_no_colors[] = { [RZ_LOGLVL_VERBOSE] = "VERBOSE", [RZ_LOGLVL_DEBUG] = "DEBUG", [RZ_LOGLVL_INFO] = "INFO", [RZ_LOGLVL_WARN] = "WARNING", [RZ_LOGLVL_ERROR] = "ERROR", - [RZ_LOGLVL_FATAL] = "FATAL" + [RZ_LOGLVL_FATAL] = "FATAL", }; -// cconfig.c configuration callback functions below +static const char *level_tags_colors[] = { + [RZ_LOGLVL_VERBOSE] = Color_GREEN "VERBOSE" Color_RESET, + [RZ_LOGLVL_DEBUG] = Color_BLUE "DEBUG" Color_RESET, + [RZ_LOGLVL_INFO] = Color_CYAN "INFO" Color_RESET, + [RZ_LOGLVL_WARN] = Color_YELLOW "WARNING" Color_RESET, + [RZ_LOGLVL_ERROR] = Color_RED "ERROR" Color_RESET, + [RZ_LOGLVL_FATAL] = Color_MAGENTA "FATAL" Color_RESET, +}; + +static log_config_t logcfg = { 0 }; + +static void log_init() { + if (logcfg.lock) { + return; + } + logcfg.callbacks = NULL; + logcfg.level = RZ_DEFAULT_LOGLVL; +#if RZ_BUILD_DEBUG + logcfg.abortlevel = RZ_DEFAULT_LOGLVL_ABORT; +#endif + logcfg.show_sources = false; + logcfg.file = NULL; + logcfg.tags = level_tags_no_colors; + logcfg.lock = rz_th_lock_new(false); +} + +/** + * \brief Sets the log level + * + * \param[in] level The log level to set. + */ RZ_API void rz_log_set_level(RzLogLevel level) { - cfg_loglvl = level; -} - -RZ_API void rz_log_set_traplevel(RzLogLevel level) { - cfg_logtraplvl = level; -} - -RZ_API void rz_log_set_file(const char *filename) { - int value_len = rz_str_nlen(filename, LOG_CONFIGSTR_SIZE) + 1; - strncpy(cfg_logfile, filename, value_len); -} - -RZ_API void rz_log_set_srcinfo(bool show_info) { - cfg_logsrcinfo = show_info; -} - -RZ_API void rz_log_set_colors(bool show_info) { - cfg_logcolors = show_info; + log_init(); + rz_th_lock_enter(logcfg.lock); + logcfg.level = level; + rz_th_lock_leave(logcfg.lock); } /** - * \brief Add a logging callback - * \param cbfunc RzLogCallback style function to be called + * \brief Sets the log level when to abort execution + * + * \param[in] level The abort log level to set. */ -RZ_API void rz_log_add_callback(RzLogCallback cbfunc) { - if (!log_cbs) { - log_cbs = rz_list_new(); - } - if (!rz_list_contains(log_cbs, cbfunc)) { - rz_list_append(log_cbs, cbfunc); - } +RZ_API void rz_log_set_abortlevel(RzLogLevel level) { + log_init(); +#if RZ_BUILD_DEBUG + rz_th_lock_enter(logcfg.lock); + logcfg.abortlevel = level; + rz_th_lock_leave(logcfg.lock); +#else + (void)level; +#endif } /** - * \brief Remove a logging callback + * \brief When not empty, enable logging to a file. + * This method allows to enable or disable logging to a file. + * To enable logging, just pass a filename to write to and to + * disable the logging is enough to pass an empty or NULL filename. + * + * \param[in] filename The file name to log to. + */ +RZ_API bool rz_log_set_file(RZ_NULLABLE const char *filename) { + log_init(); + rz_th_lock_enter(logcfg.lock); + bool ret = true; + if (logcfg.file) { + // if already open, then close the file handler. + fclose(logcfg.file); + logcfg.file = NULL; + } + + if (RZ_STR_ISEMPTY(filename)) { + // allow to have no filename + goto end; + } + + FILE *file = rz_sys_fopen(filename, "a+"); + if (!file) { + file = rz_sys_fopen(filename, "w+"); + } + if (file) { + logcfg.file = file; + } else { + // failed to open the file. + ret = false; + } + +end: + rz_th_lock_leave(logcfg.lock); + return ret; +} + +/** + * \brief When true, shows the function name and the source lines in the logs. + * + * \param[in] show_sources The boolean value to set show_sources to. + */ +RZ_API void rz_log_set_show_sources(bool show_sources) { + log_init(); + rz_th_lock_enter(logcfg.lock); + logcfg.show_sources = show_sources; + rz_th_lock_leave(logcfg.lock); +} + +/** + * \brief Enables colored logs. + * + * \param[in] show_colors Sets the pointer to colored or not colored tags. + */ +RZ_API void rz_log_set_colors(bool show_colors) { + log_init(); + rz_th_lock_enter(logcfg.lock); + logcfg.tags = show_colors ? level_tags_colors : level_tags_no_colors; + rz_th_lock_leave(logcfg.lock); +} + +/** + * \brief Adds a logging callback. + * + * \param[in] show_colors RzLogCallback style function to be called. + */ +RZ_API void rz_log_add_callback(RZ_NULLABLE RzLogCallback cbfunc) { + if (!cbfunc) { + return; + } + log_init(); + rz_th_lock_enter(logcfg.lock); + if (!logcfg.callbacks) { + logcfg.callbacks = rz_list_new(); + } + if (!rz_list_contains(logcfg.callbacks, cbfunc)) { + rz_list_append(logcfg.callbacks, cbfunc); + } + rz_th_lock_leave(logcfg.lock); +} + +/** + * \brief Removes a logging callback + * * \param cbfunc RzLogCallback style function to be called */ -RZ_API void rz_log_del_callback(RzLogCallback cbfunc) { - if (log_cbs) { - rz_list_delete_data(log_cbs, cbfunc); +RZ_API void rz_log_del_callback(RZ_NULLABLE RzLogCallback cbfunc) { + if (!cbfunc) { + return; } + log_init(); + rz_th_lock_enter(logcfg.lock); + if (logcfg.callbacks) { + rz_list_delete_data(logcfg.callbacks, cbfunc); + } + rz_th_lock_leave(logcfg.lock); } +#if RZ_BUILD_DEBUG +#define is_log_quiet(x) ((x) < logcfg.level && (x) < logcfg.abortlevel) +#else +#define is_log_quiet(x) ((x) < logcfg.level) +#endif /* RZ_BUILD_DEBUG */ + RZ_API void rz_vlog(const char *funcname, const char *filename, ut32 lineno, RzLogLevel level, const char *tag, const char *fmtstr, va_list args) { - va_list args_copy; - va_copy(args_copy, args); + log_init(); - if (level < cfg_loglvl && level < cfg_logtraplvl) { + if (is_log_quiet(level)) { // Don't print if output level is lower than current level // Don't ignore fatal/trap errors - va_end(args_copy); return; } - // TODO: Colors + // copy args only if we print the log + va_list args_copy; + va_copy(args_copy, args); // Build output string with src info, and formatted output RzStrBuf sb; rz_strbuf_init(&sb); if (!tag) { - tag = RZ_BETWEEN(0, level, RZ_ARRAY_SIZE(level_tags) - 1) ? level_tags[level] : ""; + tag = RZ_BETWEEN(0, level, (RZ_LOGLVL_SIZE - 1)) ? logcfg.tags[level] : ""; } rz_strbuf_append(&sb, tag); rz_strbuf_append(&sb, ": "); - if (cfg_logsrcinfo) { + if (logcfg.show_sources) { rz_strbuf_appendf(&sb, "%s in %s:%i: ", funcname, filename, lineno); } rz_strbuf_vappendf(&sb, fmtstr, args); - // Actually print out the string with our callbacks char *output_buf = rz_strbuf_drain_nofree(&sb); - if (log_cbs && rz_list_length(log_cbs) > 0) { + + // critical section + rz_th_lock_enter(logcfg.lock); + if (rz_list_length(logcfg.callbacks) > 0) { + // Print the log using the callbacks RzListIter *it; RzLogCallback cb; - - rz_list_foreach (log_cbs, it, cb) { + rz_list_foreach (logcfg.callbacks, it, cb) { cb(output_buf, funcname, filename, lineno, level, NULL, fmtstr, args_copy); } } else { - fprintf(stderr, "%s", output_buf); + // Print the log using stderr + fputs(output_buf, stderr); } va_end(args_copy); // Log to file if enabled - if (cfg_logfile[0] != 0x00) { - FILE *file = rz_sys_fopen(cfg_logfile, "a+"); // TODO: Optimize (static? Needs to remake on cfg change though) - if (!file) { - file = rz_sys_fopen(cfg_logfile, "w+"); - } - if (file) { - fprintf(file, "%s", output_buf); - fclose(file); - } else { - eprintf("%s failed to write to file: %s\n", MACRO_LOG_FUNC, cfg_logfile); - } + if (logcfg.file) { + fputs(output_buf, logcfg.file); + fflush(logcfg.file); } - if (level >= cfg_logtraplvl && level != RZ_LOGLVL_NONE) { - fflush(stdout); // We're about to exit HARD, flush buffers before dying +#if RZ_BUILD_DEBUG + if (level >= logcfg.abortlevel && level != RZ_LOGLVL_NONE) { + // this will abort the execution + // rz_sys_breakpoint is going to be called so we must flush buffers. + fflush(stdout); fflush(stderr); - // TODO: call rz_cons_flush if librz_cons is being used - rz_sys_breakpoint(); // *oof* + rz_sys_breakpoint(); } +#endif + rz_th_lock_leave(logcfg.lock); free(output_buf); } diff --git a/test/db/archos/linux-x64/dbg_oo b/test/db/archos/linux-x64/dbg_oo index ebe44077ce..9b2d83e4de 100644 --- a/test/db/archos/linux-x64/dbg_oo +++ b/test/db/archos/linux-x64/dbg_oo @@ -94,7 +94,7 @@ RUN NAME=dm flags after ood FILE=bins/elf/analysis/x86-helloworld-gcc -ARGS=-e log.level=5 +ARGS=-e log.level=4 CMDS=<