diff --git a/examples/config.sample b/examples/config.sample index 899f5068..66b1c7e6 100644 --- a/examples/config.sample +++ b/examples/config.sample @@ -30,7 +30,7 @@ #ReportStats = false # Logging verbosity (stderr) -# Valid values: , , or +# Valid values: , , , or # Default: #DebugLogLevel = info diff --git a/mavlink-router.service.in b/mavlink-router.service.in index 5c0f7e3b..e901d2b5 100644 --- a/mavlink-router.service.in +++ b/mavlink-router.service.in @@ -3,7 +3,7 @@ Description=MAVLink Router [Service] Type=simple -ExecStart=@BINDIR@/mavlink-routerd +ExecStart=@BINDIR@/mavlink-routerd --syslog Restart=on-failure [Install] diff --git a/src/common/log.cpp b/src/common/log.cpp index be13a239..cf7b92f9 100644 --- a/src/common/log.cpp +++ b/src/common/log.cpp @@ -22,6 +22,7 @@ #include #include #include +#include #include #define COLOR_RED "\033[31m" @@ -34,6 +35,7 @@ Log::Level Log::_max_level = Level::INFO; int Log::_target_fd = -1; bool Log::_show_colors; +Log::Backend Log::_backend = Log::Backend::STDERR; const char *Log::_get_color(Level level) { @@ -52,20 +54,30 @@ const char *Log::_get_color(Level level) return COLOR_WHITE; case Level::DEBUG: return COLOR_LIGHTBLUE; + case Level::TRACE: + break; } return nullptr; } -int Log::open() +int Log::open(Backend backend) { assert_or_return(_target_fd < 0, -1); - /* for now, only logging is supported only to stderr */ - _target_fd = STDERR_FILENO; + _backend = backend; - if (isatty(_target_fd)) { - _show_colors = true; + switch (backend) { + case Backend::STDERR: + _target_fd = STDERR_FILENO; + + if (isatty(_target_fd)) + _show_colors = true; + + break; + case Backend::SYSLOG: + openlog(nullptr, LOG_CONS, LOG_USER); + break; } return 0; @@ -73,8 +85,15 @@ int Log::open() int Log::close() { - /* see _target_fd on open() */ - fflush(stderr); + switch (_backend) { + case Backend::STDERR: + /* see _target_fd on open() */ + fflush(stderr); + break; + case Backend::SYSLOG: + closelog(); + break; + } return 0; } @@ -84,7 +103,7 @@ void Log::set_max_level(Level level) _max_level = level; } -void Log::logv(Level level, const char *format, va_list ap) +void Log::logv_to_fd(int fd, Log::Level level, const char *format, va_list ap) { struct iovec iovec[6] = {}; const char *color; @@ -92,10 +111,6 @@ void Log::logv(Level level, const char *format, va_list ap) char buffer[LINE_MAX]; int save_errno; - if (_max_level < level) { - return; - } - /* so %m works as expected */ save_errno = errno; @@ -120,7 +135,26 @@ void Log::logv(Level level, const char *format, va_list ap) IOVEC_SET_STRING(iovec[n++], "\n"); - (void)writev(_target_fd, iovec, n); + (void)writev(fd, iovec, n); +} + +void Log::logv(Level level, const char *format, va_list ap) +{ + if (_max_level < level) { + return; + } + + switch (_backend) { + case Backend::STDERR: + logv_to_fd(_target_fd, level, format, ap); + break; + case Backend::SYSLOG: +#pragma GCC diagnostic push +#pragma GCC diagnostic ignored "-Wformat-nonliteral" + vsyslog(syslog_log_level(level), format, ap); +#pragma GCC diagnostic pop + break; + } } void Log::log(Level level, const char *format, ...) @@ -131,3 +165,22 @@ void Log::log(Level level, const char *format, ...) logv(level, format, ap); va_end(ap); } + +int Log::syslog_log_level(Log::Level level) +{ + switch (level) { + case Level::ERROR: + return LOG_ERR; + case Level::WARNING: + return LOG_WARNING; + case Level::NOTICE: + return LOG_NOTICE; + case Level::INFO: + return LOG_INFO; + case Level::DEBUG: + return LOG_DEBUG; + case Level::TRACE: + return LOG_DEBUG; + } + return LOG_DEBUG; +} diff --git a/src/common/log.h b/src/common/log.h index 0c706557..b07f86cf 100644 --- a/src/common/log.h +++ b/src/common/log.h @@ -31,9 +31,15 @@ class Log { NOTICE, INFO, DEBUG, + TRACE, }; - static int open(); + enum class Backend { + STDERR, + SYSLOG, + }; + + static int open(Backend backend); static int close(); static Level get_max_level() _pure_ { return _max_level; } @@ -43,13 +49,18 @@ class Log { static void log(Level level, const char *format, ...) _printf_format_(2, 3); protected: + static void logv_to_fd(int fd, Level level, const char *format, va_list ap); static const char *_get_color(Level level); + static int syslog_log_level(Level level); + static int _target_fd; static Level _max_level; static bool _show_colors; + static Backend _backend; }; +#define log_trace(...) Log::log(Log::Level::TRACE, __VA_ARGS__) #define log_debug(...) Log::log(Log::Level::DEBUG, __VA_ARGS__) #define log_info(...) Log::log(Log::Level::INFO, __VA_ARGS__) #define log_notice(...) Log::log(Log::Level::NOTICE, __VA_ARGS__) diff --git a/src/endpoint.cpp b/src/endpoint.cpp index 5f53471d..444f52f2 100644 --- a/src/endpoint.cpp +++ b/src/endpoint.cpp @@ -231,11 +231,11 @@ int Endpoint::handle_read() // check incoming message filters if (!allowed_by_dedup(&buf)) { if (Log::get_max_level() >= Log::Level::DEBUG) { - log_debug("Message %u discarded by de-duplication", buf.curr.msg_id); + log_trace("Message %u discarded by de-duplication", buf.curr.msg_id); } } else if (!allowed_by_incoming_filters(&buf)) { if (Log::get_max_level() >= Log::Level::DEBUG) { - log_debug("Message %u to %d/%d from %u/%u discarded by incoming filters", + log_trace("Message %u to %d/%d from %u/%u discarded by incoming filters", buf.curr.msg_id, buf.curr.target_sysid, buf.curr.target_compid, @@ -292,7 +292,7 @@ int Endpoint::read_msg(struct buffer *pbuf) return r; } - log_debug("> %s [%d]%s: Got %zd bytes", _type.c_str(), fd, _name.c_str(), r); + log_trace("> %s [%d]%s: Got %zd bytes", _type.c_str(), fd, _name.c_str(), r); rx_buf.len += r; } @@ -411,7 +411,7 @@ int Endpoint::read_msg(struct buffer *pbuf) target_compid = -1; if (msg_entry == nullptr) { - log_debug("%s [%d]%s: No message entry for %u", _type.c_str(), fd, _name.c_str(), msg_id); + log_trace("%s [%d]%s: No message entry for %u", _type.c_str(), fd, _name.c_str(), msg_id); } else { if (msg_entry->flags & MAV_MSG_ENTRY_FLAG_HAVE_TARGET_SYSTEM) { // if target_system is 0, it may have been trimmed out on mavlink2 @@ -502,8 +502,8 @@ bool Endpoint::has_sys_comp_id(unsigned sys_comp_id) const Endpoint::AcceptState Endpoint::accept_msg(const struct buffer *pbuf) const { - if (Log::get_max_level() >= Log::Level::DEBUG) { - log_debug("Endpoint [%d]%s: got message %u to %d/%d from %u/%u", + if (Log::get_max_level() >= Log::Level::TRACE) { + log_trace("Endpoint [%d]%s: got message %u to %d/%d from %u/%u", fd, _name.c_str(), pbuf->curr.msg_id, @@ -511,9 +511,9 @@ Endpoint::AcceptState Endpoint::accept_msg(const struct buffer *pbuf) const pbuf->curr.target_compid, pbuf->curr.src_sysid, pbuf->curr.src_compid); - log_debug("\tKnown components:"); + log_trace("\tKnown components:"); for (const auto &id : _sys_comp_ids) { - log_debug("\t\t%u/%u", (id >> 8), id & 0xff); + log_trace("\t\t%u/%u", (id >> 8), id & 0xff); } } @@ -1024,7 +1024,7 @@ int UartEndpoint::write_msg(const struct buffer *pbuf) pbuf->len); } - log_debug("UART [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); + log_trace("UART [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); return r; } @@ -1350,7 +1350,7 @@ int UdpEndpoint::write_msg(const struct buffer *pbuf) } if (!sock_connected) { - log_debug("UDP %s: No one ever connected to us. No one to write for", _name.c_str()); + log_trace("UDP %s: No one ever connected to us. No one to write for", _name.c_str()); return 0; } @@ -1374,7 +1374,7 @@ int UdpEndpoint::write_msg(const struct buffer *pbuf) pbuf->len); } - log_debug("UDP [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); + log_trace("UDP [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); return r; } @@ -1733,7 +1733,7 @@ int TcpEndpoint::write_msg(const struct buffer *pbuf) pbuf->len); } - log_debug("TCP [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); + log_trace("TCP [%d]%s: Wrote %zd bytes", fd, _name.c_str(), r); return r; } diff --git a/src/main.cpp b/src/main.cpp index f5381e89..e9dd1ae6 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -50,12 +50,13 @@ static const struct option long_options[] = {{"endpoints", required_argument, nu {"log", required_argument, nullptr, 'l'}, {"telemetry-log", no_argument, nullptr, 'T'}, {"debug-log-level", required_argument, nullptr, 'g'}, + {"syslog", no_argument, NULL, 'y'}, {"verbose", no_argument, nullptr, 'v'}, {"version", no_argument, nullptr, 'V'}, {"sniffer-sysid", required_argument, nullptr, 's'}, {}}; -static const char *short_options = "he:rt:c:d:l:p:g:vV:s:T:"; +static const char *short_options = "he:rt:c:d:l:p:g:vV:s:T:y"; static void help(FILE *fp) { @@ -86,6 +87,7 @@ static void help(FILE *fp) " -v --verbose Verbose. Same as --debug-log-level=debug\n" " -V --version Show version\n" " -s --sniffer-sysid Sysid that all messages are sent to.\n" + " -y --syslog Use syslog output instead of stderr\n" " -h --help Print this message\n", program_invocation_short_name); } @@ -137,6 +139,9 @@ static Log::Level log_level_from_str(const char *str) if (strcaseeq(str, "debug")) { return Log::Level::DEBUG; } + if (strcaseeq(str, "trace")) { + return Log::Level::TRACE; + } throw std::invalid_argument("log_level_from_str: unkown string value"); } @@ -160,6 +165,10 @@ static bool pre_parse_argv(int argc, char *argv[], Configuration &config) config.conf_dir = optarg; break; } + case 'y': { + config.log_backend = Log::Backend::SYSLOG; + break; + } case 'V': printf(PACKAGE " version %s\n", BUILD_VERSION); return false; @@ -296,6 +305,7 @@ static int parse_argv(int argc, char *argv[], Configuration &config) } case 'c': case 'd': + case 'y': case 'V': break; // These options were parsed on pre_parse_argv case '?': @@ -595,14 +605,13 @@ int main(int argc, char *argv[]) int retcode; Configuration config{}; - Log::open(); - log_info(PACKAGE " version %s", BUILD_VERSION); - if (!pre_parse_argv(argc, argv, config)) { - Log::close(); return 0; } + Log::open(config.log_backend); + log_info(PACKAGE " version %s", BUILD_VERSION); + // Build remaining config from config files and CLI parameters if (parse_conf_files(config) < 0) { goto close_log; diff --git a/src/mainloop.cpp b/src/mainloop.cpp index cc816cc3..23456d0b 100644 --- a/src/mainloop.cpp +++ b/src/mainloop.cpp @@ -164,7 +164,7 @@ void Mainloop::route_msg(struct buffer *buf) switch (acceptState) { case Endpoint::AcceptState::Accepted: - log_debug("Endpoint [%d] accepted message %u to %d/%d from %u/%u", + log_trace("Endpoint [%d] accepted message %u to %d/%d from %u/%u", e->fd, buf->curr.msg_id, buf->curr.target_sysid, @@ -177,7 +177,7 @@ void Mainloop::route_msg(struct buffer *buf) unknown = false; break; case Endpoint::AcceptState::Filtered: - log_debug("Endpoint [%d] filtered out message %u to %d/%d from %u/%u", + log_trace("Endpoint [%d] filtered out message %u to %d/%d from %u/%u", e->fd, buf->curr.msg_id, buf->curr.target_sysid, @@ -195,7 +195,7 @@ void Mainloop::route_msg(struct buffer *buf) if (unknown) { _errors_aggregate.msg_to_unknown++; - log_debug("Message %u to unknown sysid/compid: %d/%d", + log_trace("Message %u to unknown sysid/compid: %d/%d", buf->curr.msg_id, buf->curr.target_sysid, buf->curr.target_compid); diff --git a/src/mainloop.h b/src/mainloop.h index 59cde3d6..0d13b86c 100644 --- a/src/mainloop.h +++ b/src/mainloop.h @@ -36,7 +36,8 @@ struct Configuration { unsigned long tcp_port{5760}; ///< conf "TcpServerPort" or CLI "tcp-port" bool report_msg_statistics{false}; ///< conf "ReportStats" or CLI "report_msg_statistics" Log::Level debug_log_level{Log::Level::INFO}; ///< conf "DebugLogLevel" or CLI "debug-log-level" - unsigned long dedup_period_ms; ///< conf "DeduplicationPeriod" + Log::Backend log_backend{Log::Backend::STDERR}; ///< CLI "syslog" + unsigned long dedup_period_ms; ///< conf "DeduplicationPeriod" LogOptions log_config; ///< logging is in General config section, but internally an endpoint std::vector uart_configs;