From 1a8703ec1c0aee86aa2440fc8b7cd627f65854a9 Mon Sep 17 00:00:00 2001 From: Mark Charlebois Date: Wed, 17 Jun 2015 13:28:27 -0700 Subject: [PATCH] Improved logging with both compile and runtime level filtering The device level debug will have to be removed and the debugging can be based on this new logging structure which can tell where an error (or debug output) occured whch the current implmentation cannot. The one limitation is the new macros cannot take a char* for the format parameter. It must be an actual string literal because it is concatenated with other strings. Signed-off-by: Mark Charlebois --- src/drivers/device/device_posix.cpp | 17 +- .../commander/state_machine_helper.cpp | 7 +- src/platforms/common/module.mk | 3 +- src/platforms/common/px4_log.c | 5 + src/platforms/px4_log.h | 178 +++++++++++------- 5 files changed, 129 insertions(+), 81 deletions(-) create mode 100644 src/platforms/common/px4_log.c diff --git a/src/drivers/device/device_posix.cpp b/src/drivers/device/device_posix.cpp index 7d83842266..771bee2471 100644 --- a/src/drivers/device/device_posix.cpp +++ b/src/drivers/device/device_posix.cpp @@ -85,11 +85,10 @@ Device::log(const char *fmt, ...) PX4_INFO("[%s] ", _name); va_start(ap, fmt); - PX4_INFO( fmt, ap ); - //vprintf(fmt, ap); + vprintf(fmt, ap); va_end(ap); - //printf("\n"); - //fflush(stdout); + printf("\n"); + fflush(stdout); } void @@ -98,14 +97,12 @@ Device::debug(const char *fmt, ...) va_list ap; if (_debug_enabled) { - PX4_INFO("<%s> ", _name); - //printf("<%s> ", _name); + printf("<%s> ", _name); va_start(ap, fmt); - //vprintf(fmt, ap); - PX4_INFO(fmt, ap); + vprintf(fmt, ap); va_end(ap); - //printf("\n"); - //fflush(stdout); + printf("\n"); + fflush(stdout); } } diff --git a/src/modules/commander/state_machine_helper.cpp b/src/modules/commander/state_machine_helper.cpp index 8d49c305e1..ba5dee9be9 100644 --- a/src/modules/commander/state_machine_helper.cpp +++ b/src/modules/commander/state_machine_helper.cpp @@ -269,14 +269,15 @@ arming_state_transition(struct vehicle_status_s *status, ///< current vehicle s } if (ret == TRANSITION_DENIED) { - const char * str = "INVAL: %s - %s"; +#define WARNSTR "INVAL: %s - %s" /* only print to console here by default as this is too technical to be useful during operation */ - warnx(str, state_names[status->arming_state], state_names[new_arming_state]); + warnx(WARNSTR, state_names[status->arming_state], state_names[new_arming_state]); /* print to MAVLink if we didn't provide any feedback yet */ if (!feedback_provided) { - mavlink_log_critical(mavlink_fd, str, state_names[status->arming_state], state_names[new_arming_state]); + mavlink_log_critical(mavlink_fd, WARNSTR, state_names[status->arming_state], state_names[new_arming_state]); } +#undef WARNSTR } return ret; diff --git a/src/platforms/common/module.mk b/src/platforms/common/module.mk index 0e5f463e69..472dc7dba6 100644 --- a/src/platforms/common/module.mk +++ b/src/platforms/common/module.mk @@ -2,5 +2,6 @@ # Common OS porting APIs # -SRCS = px4_getopt.c +SRCS = px4_getopt.c \ + px4_log.c diff --git a/src/platforms/common/px4_log.c b/src/platforms/common/px4_log.c new file mode 100644 index 0000000000..0ee4c2a6ad --- /dev/null +++ b/src/platforms/common/px4_log.c @@ -0,0 +1,5 @@ +#include + +__EXPORT unsigned int __px4_log_level_current = PX4_LOG_LEVEL_AT_RUN_TIME; + +__EXPORT const char *__px4_log_level_str[_PX4_LOG_LEVEL_DEBUG+1] = { "INFO", "PANIC", "ERROR", "WARN", "DEBUG" }; diff --git a/src/platforms/px4_log.h b/src/platforms/px4_log.h index 5576025362..57dbf3e503 100644 --- a/src/platforms/px4_log.h +++ b/src/platforms/px4_log.h @@ -32,92 +32,136 @@ ****************************************************************************/ /** - * @file px4_log.h - * Platform dependant logging/debug + * @file px4_log_os_impl.h + * Platform dependant logging/debug implementation */ #pragma once -#define __px4_log_omit(level, ...) { } - -#define __px4_log(level, ...) { \ - printf("%-5s ", level);\ - printf(__VA_ARGS__);\ - printf("\n");\ -} -#define __px4_log_verbose(level, ...) { \ - printf("%-5s ", level);\ - printf(__VA_ARGS__);\ - printf(" (file %s line %d)\n", __FILE__, __LINE__);\ -} -#if defined(__PX4_QURT) +#define __STDC_FORMAT_MACROS +#include +#include +#include #include -#define FARF printf -#define __FARF_omit(level, ...) { } -#define __FARF_log(level, ...) { \ - FARF("%-5s ", level);\ - FARF(__VA_ARGS__);\ - FARF("\n");\ -} -#define __FARF_log_verbose(level, ...) { \ - FARF("%-5s ", level);\ - FARF(__VA_ARGS__);\ - FARF(" (file %s line %d)\n", __FILE__, __LINE__);\ -} +__BEGIN_DECLS +__EXPORT extern uint64_t hrt_absolute_time(void); +//__EXPORT extern unsigned long pthread_self(); -#define PX4_DEBUG(...) __FARF_omit("DEBUG", __VA_ARGS__) -#define PX4_INFO(...) __FARF_log("INFO", __VA_ARGS__) -#define PX4_WARN(...) __FARF_log_verbose("WARN", __VA_ARGS__) -#define PX4_ERR(...) __FARF_log_verbose("ERROR", __VA_ARGS__) +#define _PX4_LOG_LEVEL_ALWAYS 0 +#define _PX4_LOG_LEVEL_PANIC 1 +#define _PX4_LOG_LEVEL_ERROR 2 +#define _PX4_LOG_LEVEL_WARN 3 +#define _PX4_LOG_LEVEL_DEBUG 4 -#elif defined(__PX4_LINUX) -#include -#include +extern const char *__px4_log_level_str[5]; +extern unsigned int __px4_log_level_current; -#define __px4_log_threads(level, ...) { \ - printf("%-5s %ld ", level, pthread_self());\ - printf(__VA_ARGS__);\ - printf(" (file %s line %d)\n", __FILE__, __LINE__);\ -} +#define PX4_LOG_LEVEL_AT_RUN_TIME _PX4_LOG_LEVEL_WARN -#define PX4_DEBUG(...) __px4_log_omit("DEBUG", __VA_ARGS__) -#define PX4_INFO(...) __px4_log("INFO", __VA_ARGS__) -#define PX4_WARN(...) __px4_log_verbose("WARN", __VA_ARGS__) -#define PX4_ERR(...) __px4_log_verbose("ERROR", __VA_ARGS__) +#define _PX4_LOG_LEVEL_STR(level) __px4_log_level_str[level]; -#elif defined(__PX4_DARWIN) -#include -#include +/**************************************************************************** + * Implementation of log section formatting based on printf + ****************************************************************************/ +#if defined(__PX4_ROS) +#define __px4__log_startline(level) if (level <= __px4_log_level_current) ROS_WARN( +#else +#define __px4__log_startline(level) if (level <= __px4_log_level_current) printf( +#endif +#define __px4__log_timestamp_fmt "%-10" PRIu64 +#define __px4__log_timestamp_arg ,hrt_absolute_time() +#define __px4__log_level_fmt "%-5s " +#define __px4__log_level_arg(level) ,__px4_log_level_str[level] +#define __px4__log_thread_fmt "%ld " +#define __px4__log_thread_arg ,pthread_self() -#define __px4_log_threads(level, ...) { \ - printf("%-5s %ld ", level, pthread_self());\ - printf(__VA_ARGS__);\ - printf(" (file %s line %d)\n", __FILE__, __LINE__);\ -} +#define __px4__log_file_and_line_fmt " (file %s line %d)" +#define __px4__log_file_and_line_arg , __FILE__, __LINE__ +#define __px4__log_end_fmt "\n" +#define __px4__log_endline ) -#define PX4_DEBUG(...) __px4_log_omit("DEBUG", __VA_ARGS__) -#define PX4_INFO(...) __px4_log("INFO", __VA_ARGS__) -#define PX4_WARN(...) __px4_log_verbose("WARN", __VA_ARGS__) -#define PX4_ERR(...) __px4_log_verbose("ERROR", __VA_ARGS__) +/**************************************************************************** + * Output format macros + * Use these to implement the code level macros below + ****************************************************************************/ +#define __px4_log_omit(level, FMT, ...) { } -#elif defined(__PX4_ROS) +#define __px4_log(level, FMT, ...) \ + __px4__log_startline(level)\ + __px4__log_level_fmt \ + FMT\ + __px4__log_end_fmt \ + __px4__log_level_arg(level), ##__VA_ARGS__\ + __px4__log_endline -#define PX4_DBG(...) -#define PX4_INFO(...) ROS_WARN(__VA_ARGS__) -#define PX4_WARN(...) ROS_WARN(__VA_ARGS__) -#define PX4_ERR(...) ROS_WARN(__VA_ARGS__) +#define __px4_log_timestamp(level, FMT, ...) \ + __px4__log_startline(level)\ + __px4__log_timestamp_fmt\ + __px4__log_level_fmt\ + FMT\ + __px4__log_end_fmt\ + __px4__log_timestamp_arg\ + __px4__log_level_arg(level), ##__VA_ARGS__\ + __px4__log_endline -#elif defined(__PX4_NUTTX) -#include +#define __px4_log_file_and_line(level, FMT, ...) \ + __px4__log_startline(level)\ + __px4__log_timestamp_fmt\ + __px4__log_level_fmt\ + FMT\ + __px4__log_file_and_line_fmt\ + __px4__log_end_fmt\ + __px4__log_timestamp_arg\ + __px4__log_level_arg(level), ##__VA_ARGS__\ + __px4__log_file_and_line_arg\ + __px4__log_endline -#define PX4_DBG(...) -#define PX4_INFO(...) warnx(__VA_ARGS__) -#define PX4_WARN(...) warnx(__VA_ARGS__) -#define PX4_ERR(...) warnx(__VA_ARGS__) +#define __px4_log_timestamp_file_and_line(level, FMT, ...) \ + __px4__log_startline(level)\ + __px4__log_timestamp_fmt\ + __px4__log_level_fmt\ + FMT\ + __px4__log_file_and_line_fmt\ + __px4__log_end_fmt\ + __px4__log_timestamp_arg\ + __px4__log_level_arg(level) , ##__VA_ARGS__\ + __px4__log_file_and_line_arg\ + __px4__log_endline + +#define __px4_log_thread_file_and_line(level, FMT, ...) \ + __px4__log_startline(level)\ + __px4__log_thread_fmt\ + __px4__log_level_fmt\ + FMT\ + __px4__log_file_and_line_fmt\ + __px4__log_end_fmt\ + __px4__log_thread_arg\ + __px4__log_level_arg(level) , ##__VA_ARGS__\ + __px4__log_file_and_line_arg\ + __px4__log_endline + + +/**************************************************************************** + * Code level macros + * These are the log APIs that should be used by the code + ****************************************************************************/ +#define PX4_LOG(FMT, ...) __px4_log(_PX4_LOG_LEVEL_ALWAYS, FMT, __VA_ARGS__) + +#if defined(DEBUG_BUILD) + +#define PX4_PANIC(FMT, ...) __px4_log_timestamp_file_and_line(_PX4_LOG_LEVEL_PANIC, FMT, ##__VA_ARGS__) +#define PX4_ERR(FMT, ...) __px4_log_timestamp_file_and_line(_PX4_LOG_LEVEL_ERROR, FMT, ##__VA_ARGS__) +#define PX4_WARN(FMT, ...) __px4_log_timestamp_file_and_line(_PX4_LOG_LEVEL_WARN, FMT, ##__VA_ARGS__) +#define PX4_DEBUG(FMT, ...) __px4_log_timestamp(_PX4_LOG_LEVEL_DEBUG, FMT, __VA_ARGS__) #else -#error "Target platform unknown" +#define PX4_PANIC(FMT, ...) __px4_log_file_and_line(_PX4_LOG_LEVEL_PANIC, FMT, ##__VA_ARGS__) +#define PX4_ERR(FMT, ...) __px4_log_file_and_line(_PX4_LOG_LEVEL_ERROR, FMT, ##__VA_ARGS__) +#define PX4_WARN(FMT, ...) __px4_log_file_and_line(_PX4_LOG_LEVEL_WARN, FMT, ##__VA_ARGS__) +#define PX4_INFO(FMT, ...) __px4_log(_PX4_LOG_LEVEL_WARN, FMT, ##__VA_ARGS__) +#define PX4_DEBUG(FMT, ...) __px4_log_omit(_PX4_LOG_LEVEL_DEBUG, FMT, ##__VA_ARGS__) #endif +__END_DECLS