From cd148cda88233809922818895f9287f51151bc9b Mon Sep 17 00:00:00 2001 From: Lorenz Meier Date: Tue, 2 Feb 2021 00:49:07 +0100 Subject: [PATCH] Revert "platforms: px4 log build string then print (fputs)" This reverts commit 9e112dd48bd9f5a2df559263bd1b8e5c636d68a9. --- .vscode/cmake-variants.yaml | 10 - ROMFS/px4fmu_common/init.d-posix/rcS | 12 +- .../common/include/px4_platform_common/log.h | 10 + platforms/common/px4_log.cpp | 174 ++++++------------ platforms/posix/src/px4/common/main.cpp | 2 +- 5 files changed, 69 insertions(+), 139 deletions(-) diff --git a/.vscode/cmake-variants.yaml b/.vscode/cmake-variants.yaml index f5d14a7b59..988bdb420a 100644 --- a/.vscode/cmake-variants.yaml +++ b/.vscode/cmake-variants.yaml @@ -6,16 +6,6 @@ CONFIG: buildType: RelWithDebInfo settings: CONFIG: px4_sitl_default - px4_sitl_asan: - short: px4_sitl (AddressSanitizer) - buildType: AddressSanitizer - settings: - CONFIG: px4_sitl_default - px4_sitl_ubsan: - short: px4_sitl (UndefinedBehaviorSanitizer) - buildType: UndefinedBehaviorSanitizer - settings: - CONFIG: px4_sitl_default px4_sitl_replay: short: px4_sitl_replay buildType: RelWithDebInfo diff --git a/ROMFS/px4fmu_common/init.d-posix/rcS b/ROMFS/px4fmu_common/init.d-posix/rcS index 55fc3f12e5..edf49e203a 100644 --- a/ROMFS/px4fmu_common/init.d-posix/rcS +++ b/ROMFS/px4fmu_common/init.d-posix/rcS @@ -46,10 +46,10 @@ else # shellcheck disable=SC2012 REQUESTED_AUTOSTART=$(ls "$SCRIPT_DIR/airframes" | sed -n 's/^\([0-9][0-9]*\)_'${PX4_SIM_MODEL}'$/\1/p') if [ -z "$REQUESTED_AUTOSTART" ]; then - echo "ERROR [init] Unknown model $PX4_SIM_MODEL (not found by name on $SCRIPT_DIR/airframes)" + echo "Error: Unknown model $PX4_SIM_MODEL (not found by name on $SCRIPT_DIR/airframes)" exit 1 else - echo "INFO [init] found model autostart file as SYS_AUTOSTART=$REQUESTED_AUTOSTART" + echo "Info: found model autostart file as SYS_AUTOSTART=$REQUESTED_AUTOSTART" fi fi @@ -63,12 +63,12 @@ if [ -f $PARAM_FILE ] then if param load then - echo "INFO [init] Loaded: $PARAM_FILE" + echo "[param] Loaded: $PARAM_FILE" else - echo "ERROR [init] FAILED loading $PARAM_FILE" + echo "[param] FAILED loading $PARAM_FILE" fi else - echo "INFO [init] parameter file not found, creating $PARAM_FILE" + echo "[param] parameter file not found, creating $PARAM_FILE" fi # exit early when the minimal shell is requested @@ -192,7 +192,7 @@ do esac done if [ ! -e "$autostart_file" ]; then - echo "ERROR [init] no autostart file found ($autostart_file)" + echo "Error: no autostart file found ($autostart_file)" exit 1 fi diff --git a/platforms/common/include/px4_platform_common/log.h b/platforms/common/include/px4_platform_common/log.h index 7b36fcd50f..db759370bf 100644 --- a/platforms/common/include/px4_platform_common/log.h +++ b/platforms/common/include/px4_platform_common/log.h @@ -127,6 +127,7 @@ __END_DECLS __BEGIN_DECLS __EXPORT extern const char *__px4_log_level_str[_PX4_LOG_LEVEL_PANIC + 1]; +__EXPORT extern const char *__px4_log_level_color[_PX4_LOG_LEVEL_PANIC + 1]; __EXPORT void px4_log_modulename(int level, const char *moduleName, const char *fmt, ...) __attribute__((format(printf, 3, 4))); __EXPORT void px4_log_raw(int level, const char *fmt, ...) @@ -167,6 +168,15 @@ __END_DECLS #define __px4__log_file_and_line_arg , __FILE__, __LINE__ #define __px4__log_end_fmt "\n" +#define PX4_ANSI_COLOR_RED "\x1b[31m" +#define PX4_ANSI_COLOR_GREEN "\x1b[32m" +#define PX4_ANSI_COLOR_YELLOW "\x1b[33m" +#define PX4_ANSI_COLOR_BLUE "\x1b[34m" +#define PX4_ANSI_COLOR_MAGENTA "\x1b[35m" +#define PX4_ANSI_COLOR_CYAN "\x1b[36m" +#define PX4_ANSI_COLOR_GRAY "\x1B[37m" +#define PX4_ANSI_COLOR_RESET "\x1b[0m" + #ifdef __PX4_POSIX #define PX4_LOG_COLORIZED_OUTPUT //if defined and output is a tty, colorize the output according to the log level #endif /* __PX4_POSIX */ diff --git a/platforms/common/px4_log.cpp b/platforms/common/px4_log.cpp index 0883784fb2..803ed2f890 100644 --- a/platforms/common/px4_log.cpp +++ b/platforms/common/px4_log.cpp @@ -45,7 +45,6 @@ #include #endif -#include #include #include #include @@ -53,119 +52,68 @@ static orb_advert_t orb_log_message_pub = nullptr; __EXPORT const char *__px4_log_level_str[_PX4_LOG_LEVEL_PANIC + 1] = { "DEBUG", "INFO", "WARN", "ERROR", "PANIC" }; +__EXPORT const char *__px4_log_level_color[_PX4_LOG_LEVEL_PANIC + 1] = +{ PX4_ANSI_COLOR_GREEN, PX4_ANSI_COLOR_RESET, PX4_ANSI_COLOR_YELLOW, PX4_ANSI_COLOR_RED, PX4_ANSI_COLOR_RED }; -#define PX4_ANSI_COLOR_RED "\x1b[31m" -#define PX4_ANSI_COLOR_GREEN "\x1b[32m" -#define PX4_ANSI_COLOR_YELLOW "\x1b[33m" -#define PX4_ANSI_COLOR_BLUE "\x1b[34m" -#define PX4_ANSI_COLOR_MAGENTA "\x1b[35m" -#define PX4_ANSI_COLOR_CYAN "\x1b[36m" -#define PX4_ANSI_COLOR_GRAY "\x1B[37m" -#define PX4_ANSI_COLOR_RESET "\x1b[0m" - -static constexpr const char *__px4_log_level_color[_PX4_LOG_LEVEL_PANIC + 1] { - PX4_ANSI_COLOR_GREEN, // DEBUG - PX4_ANSI_COLOR_RESET, // INFO - PX4_ANSI_COLOR_YELLOW, // WARN - PX4_ANSI_COLOR_RED, // ERROR - PX4_ANSI_COLOR_RED // PANIC -}; void px4_log_initialize(void) { - // we need to advertise with a valid message - log_message_s log_message{}; - log_message.severity = 6; // info - strcpy((char *)log_message.text, "initialized uORB logging"); + assert(orb_log_message_pub == nullptr); + + /* we need to advertise with a valid message */ + struct log_message_s log_message; log_message.timestamp = hrt_absolute_time(); + log_message.severity = 6; //info + strcpy((char *)log_message.text, "initialized uORB logging"); + orb_log_message_pub = orb_advertise_queue(ORB_ID(log_message), &log_message, log_message_s::ORB_QUEUE_LENGTH); + + if (!orb_log_message_pub) { + PX4_ERR("failed to advertise log_message"); + } } -__EXPORT void px4_log_modulename(int level, const char *module_name, const char *fmt, ...) + +__EXPORT void px4_log_modulename(int level, const char *moduleName, const char *fmt, ...) { - static constexpr ssize_t max_length = sizeof(log_message_s::text); - FILE *out = stdout; - -#if defined(PX4_LOG_COLORIZED_OUTPUT) bool use_color = true; -#endif // PX4_LOG_COLORIZED_OUTPUT -#if defined(__PX4_POSIX) - bool isatty_ = false; - out = get_stdout(&isatty_); +#ifdef __PX4_POSIX + out = get_stdout(&use_color); +#endif -#if defined(PX4_LOG_COLORIZED_OUTPUT) - use_color = isatty_; -#endif // PX4_LOG_COLORIZED_OUTPUT -#endif // PX4_POSIX +#ifndef PX4_LOG_COLORIZED_OUTPUT + use_color = false; +#endif if (level >= _PX4_LOG_LEVEL_INFO) { - char buf[max_length + 1]; // same length as log_message_s::text, but add newline - ssize_t pos = 0; + if (use_color) { fputs(__px4_log_level_color[level], out); } -#if defined(PX4_LOG_COLORIZED_OUTPUT) + fprintf(out, __px4__log_level_fmt __px4__log_level_arg(level)); - if (use_color) { - pos += sprintf(buf + pos, "%s", __px4_log_level_color[level]); - } + if (use_color) { fputs(PX4_ANSI_COLOR_GRAY, out); } -#endif // PX4_LOG_COLORIZED_OUTPUT + fprintf(out, __px4__log_modulename_pfmt, moduleName); - pos += snprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), __px4__log_level_fmt, __px4_log_level_str[level]); - -#if defined(PX4_LOG_COLORIZED_OUTPUT) - - if (use_color) { - pos += snprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), PX4_ANSI_COLOR_GRAY); - } - -#endif // PX4_LOG_COLORIZED_OUTPUT - - pos += snprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), __px4__log_modulename_pfmt, module_name); - -#if defined(PX4_LOG_COLORIZED_OUTPUT) - - if (use_color) { - pos += snprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), "%s", __px4_log_level_color[level]); - } - -#endif // PX4_LOG_COLORIZED_OUTPUT + if (use_color) { fputs(__px4_log_level_color[level], out); } va_list argptr; va_start(argptr, fmt); - pos += vsnprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), fmt, argptr); + vfprintf(out, fmt, argptr); va_end(argptr); -#if defined(PX4_LOG_COLORIZED_OUTPUT) + if (use_color) { fputs(PX4_ANSI_COLOR_RESET, out); } - if (use_color) { - // alway reset color - const ssize_t sz = math::min(pos, max_length - (ssize_t)strlen(PX4_ANSI_COLOR_RESET) - (ssize_t)1); - pos += sprintf(buf + sz, "%s\n", PX4_ANSI_COLOR_RESET); - - } else -#endif // PX4_LOG_COLORIZED_OUTPUT - { - pos += sprintf(buf + math::min(pos, max_length - (ssize_t)1), "\n"); - } - - // ensure NULL termination (buffer is max_length + 1) - buf[max_length] = 0; - - fputs(buf, out); - -#if defined(CONFIG_ARCH_BOARD_PX4_SITL) - // Without flushing it's tricky to see stdout output when PX4 is started by - // a script like for the MAVSDK tests. - fflush(out); -#endif // CONFIG_ARCH_BOARD_PX4_SITL + fputc('\n', out); } /* publish an orb log message */ if (level >= _PX4_LOG_LEVEL_INFO && orb_log_message_pub) { //publish all messages - log_message_s log_message; + struct log_message_s log_message; + const unsigned max_length_pub = sizeof(log_message.text); + log_message.timestamp = hrt_absolute_time(); const uint8_t log_level_table[] = { 7, /* _PX4_LOG_LEVEL_DEBUG */ @@ -176,65 +124,47 @@ __EXPORT void px4_log_modulename(int level, const char *module_name, const char }; log_message.severity = log_level_table[level]; - ssize_t pos = snprintf((char *)log_message.text, max_length, __px4__log_modulename_pfmt, module_name); + unsigned pos = 0; va_list argptr; + + pos += snprintf((char *)log_message.text + pos, max_length_pub - pos, __px4__log_modulename_pfmt, moduleName); va_start(argptr, fmt); - pos += vsnprintf((char *)log_message.text + pos, math::max(max_length - pos, (ssize_t)0), fmt, argptr); + pos += vsnprintf((char *)log_message.text + pos, max_length_pub - pos, fmt, argptr); va_end(argptr); - log_message.text[max_length - 1] = 0; //ensure 0-termination - log_message.timestamp = hrt_absolute_time(); + log_message.text[max_length_pub - 1] = 0; //ensure 0-termination + orb_publish(ORB_ID(log_message), orb_log_message_pub, &log_message); } + +#ifdef CONFIG_ARCH_BOARD_PX4_SITL + // Without flushing it's tricky to see stdout output when PX4 is started by + // a script like for the MAVSDK tests. + fflush(out); +#endif } __EXPORT void px4_log_raw(int level, const char *fmt, ...) { FILE *out = stdout; + bool use_color = true; #ifdef __PX4_POSIX - bool use_color = true; out = get_stdout(&use_color); #endif +#ifndef PX4_LOG_COLORIZED_OUTPUT + use_color = false; +#endif + if (level >= _PX4_LOG_LEVEL_INFO) { - static constexpr ssize_t max_length = sizeof(log_message_s::text); - char buf[max_length + 1]; // same length as log_message_s::text, but add newline - ssize_t pos = 0; - -#if defined(PX4_LOG_COLORIZED_OUTPUT) - - if (use_color) { - pos += sprintf(buf + pos, "%s", __px4_log_level_color[level]); - } - -#endif // PX4_LOG_COLORIZED_OUTPUT + if (use_color) { fputs(__px4_log_level_color[level], out); } va_list argptr; va_start(argptr, fmt); - pos += vsnprintf(buf + pos, math::max(max_length - pos, (ssize_t)0), fmt, argptr); + vfprintf(out, fmt, argptr); va_end(argptr); -#if defined(PX4_LOG_COLORIZED_OUTPUT) - - if (use_color) { - // alway reset color - const ssize_t sz = math::min(pos, max_length - (ssize_t)strlen(PX4_ANSI_COLOR_RESET)); - pos += sprintf(buf + sz, "%s", PX4_ANSI_COLOR_RESET); - } - -#endif // PX4_LOG_COLORIZED_OUTPUT - - if (pos > max_length) { - // preserve newline if necessary - if (fmt[strlen(fmt) - 1] == '\n') { - buf[max_length - 1] = '\n'; - } - } - - // ensure NULL termination (buffer is max_length + 1) - buf[max_length] = 0; - - fputs(buf, out); + if (use_color) { fputs(PX4_ANSI_COLOR_RESET, out); } } } diff --git a/platforms/posix/src/px4/common/main.cpp b/platforms/posix/src/px4/common/main.cpp index 50b5ad5dfd..e8c29bb3e7 100644 --- a/platforms/posix/src/px4/common/main.cpp +++ b/platforms/posix/src/px4/common/main.cpp @@ -371,7 +371,7 @@ int create_symlinks_if_needed(std::string &data_path) } - PX4_INFO_RAW("Creating symlink %s -> %s\n", src_path.c_str(), dest_path.c_str()); + PX4_INFO("Creating symlink %s -> %s", src_path.c_str(), dest_path.c_str()); // create sym-link int ret = symlink(src_path.c_str(), dest_path.c_str());