logging: Add network backend

Allow logging subsystem to send the logging messages to outside
system. This backend implements RFC 5424 (syslog protocol) and
RFC 5426 (syslog over UDP).

Signed-off-by: Jukka Rissanen <jukka.rissanen@linux.intel.com>
This commit is contained in:
Jukka Rissanen 2018-10-12 17:31:57 +03:00 committed by Anas Nashif
commit 44a9bb6abe
5 changed files with 408 additions and 11 deletions

View file

@ -39,6 +39,10 @@ extern "C" {
/** @brief Flag forcing a single LF character for line breaks. */
#define LOG_OUTPUT_FLAG_CRLF_LFONLY BIT(5)
/** @brief Flag forcing syslog format specified in RFC 5424
*/
#define LOG_OUTPUT_FLAG_FORMAT_SYSLOG BIT(6)
/**
* @brief Prototype of the function processing output data.
*
@ -54,6 +58,7 @@ typedef int (*log_output_func_t)(u8_t *buf, size_t size, void *ctx);
struct log_output_control_block {
size_t offset;
void *ctx;
const char *hostname;
};
/** @brief Log_output instance structure. */
@ -110,6 +115,16 @@ static inline void log_output_ctx_set(const struct log_output *log_output,
log_output->control_block->ctx = ctx;
}
/** @brief Function for setting hostname of this device
*
* @param log_output Pointer to the log output instance.
* @param hostname Hostname of this device
*/
static inline void log_output_hostname_set(const struct log_output *log_output,
const char *hostname)
{
log_output->control_block->hostname = hostname;
}
/** @brief Set timestamp frequency.
*

View file

@ -24,6 +24,11 @@ zephyr_sources_ifdef(
log_backend_native_posix.c
)
zephyr_sources_ifdef(
CONFIG_LOG_BACKEND_NET
log_backend_net.c
)
zephyr_sources_ifdef(
CONFIG_LOG_BACKEND_RTT
log_backend_rtt.c

View file

@ -358,6 +358,53 @@ config LOG_BACKEND_NATIVE_POSIX
help
Enable backend in native_posix
config LOG_BACKEND_NET
bool "Enable networking backend"
depends on NETWORKING
select NET_CONTEXT_NET_PKT_POOL
help
Send syslog messages to network server.
See RFC 5424 (syslog protocol) and RFC 5426 (syslog over UDP)
specifications for details.
if LOG_BACKEND_NET
config LOG_BACKEND_NET_SERVER
string "Syslog server IP address"
help
This can be either IPv4 or IPv6 address.
Server listen UDP port number can be configured here too.
Following syntax is supported:
192.0.2.1:514
192.0.2.42
[2001:db8::1]:514
[2001:db8::2]
2001:db::42
config LOG_BACKEND_NET_MAX_BUF
int "How many network buffers to allocate for sending messages"
range 3 256
default 3
help
Each syslog message should fit into a network packet that will be
sent to server. This number tells how many syslog messages can be
in transit to the server.
config LOG_BACKEND_NET_MAX_BUF_SIZE
int "Max syslog message size"
range 64 1180
default 1180 if NET_IPV6
default 480 if NET_IPV4
default 256
help
As each syslog message needs to fit to UDP packet, set this value
so that messages are not truncated.
The RFC 5426 recommends that for IPv4 the size is 480 octets and for
IPv6 the size is 1180 octets. As each buffer will use RAM, the value
should be selected so that typical messages will fit the buffer.
endif # LOG_BACKEND_NET
config LOG_BACKEND_SHOW_COLOR
bool "Enable colors in the backend"
depends on LOG_BACKEND_UART || LOG_BACKEND_NATIVE_POSIX || LOG_BACKEND_RTT

View file

@ -0,0 +1,244 @@
/*
* Copyright (c) 2018 Intel Corporation
*
* SPDX-License-Identifier: Apache-2.0
*/
#include <logging/log_backend.h>
#include <logging/log_core.h>
#include <logging/log_output.h>
#include <logging/log_msg.h>
#include <net/net_pkt.h>
#include <net/net_context.h>
/* Set this to 1 if you want to see what is being sent to server */
#define DEBUG_PRINTING 0
#if DEBUG_PRINTING
#define DBG(fmt, ...) printk(fmt, ##__VA_ARGS__)
#else
#define DBG(fmt, ...)
#endif
#if defined(CONFIG_NET_IPV6) || CONFIG_NET_HOSTNAME_ENABLE
#define MAX_HOSTNAME_LEN NET_IPV6_ADDR_LEN
#else
#define MAX_HOSTNAME_LEN NET_IPV4_ADDR_LEN
#endif
static char hostname[MAX_HOSTNAME_LEN + 1];
static u8_t output_buf[CONFIG_LOG_BACKEND_NET_MAX_BUF_SIZE];
static bool net_init_done;
struct sockaddr server_addr;
static bool panic_mode;
const struct log_backend *log_backend_net_get(void);
NET_PKT_SLAB_DEFINE(syslog_tx_pkts, CONFIG_LOG_BACKEND_NET_MAX_BUF);
NET_PKT_DATA_POOL_DEFINE(syslog_tx_bufs,
ROUND_UP(CONFIG_LOG_BACKEND_NET_MAX_BUF_SIZE /
CONFIG_NET_BUF_DATA_SIZE, 1) *
CONFIG_LOG_BACKEND_NET_MAX_BUF);
static struct k_mem_slab *get_tx_slab(void)
{
return &syslog_tx_pkts;
}
struct net_buf_pool *get_data_pool(void)
{
return &syslog_tx_bufs;
}
static int line_out(u8_t *data, size_t length, void *output_ctx)
{
struct net_context *ctx = (struct net_context *)output_ctx;
int ret = -ENOMEM;
struct net_pkt *pkt;
if (!ctx) {
return length;
}
pkt = net_pkt_get_tx(ctx, K_NO_WAIT);
if (!pkt) {
goto fail;
}
if (net_pkt_append_all(pkt, length, data, K_NO_WAIT) == false) {
goto fail;
}
ret = net_context_send(pkt, NULL, K_NO_WAIT, NULL, NULL);
if (ret < 0) {
goto fail;
}
DBG(data);
fail:
if (ret < 0 && pkt) {
net_pkt_unref(pkt);
}
return length;
}
LOG_OUTPUT_DEFINE(log_output, line_out, output_buf, sizeof(output_buf));
static int do_net_init(void)
{
struct sockaddr *local_addr = NULL;
struct sockaddr_in6 local_addr6;
struct sockaddr_in local_addr4;
socklen_t server_addr_len;
struct net_context *ctx;
int ret;
if (IS_ENABLED(CONFIG_NET_IPV4) && server_addr.sa_family == AF_INET) {
local_addr = (struct sockaddr *)&local_addr4;
server_addr_len = sizeof(struct sockaddr_in);
local_addr4.sin_port = 0;
}
if (IS_ENABLED(CONFIG_NET_IPV6) && server_addr.sa_family == AF_INET6) {
local_addr = (struct sockaddr *)&local_addr6;
server_addr_len = sizeof(struct sockaddr_in6);
local_addr6.sin6_port = 0;
}
if (!local_addr) {
DBG("Server address unknown\n");
return -EINVAL;
}
local_addr->sa_family = server_addr.sa_family;
ret = net_context_get(server_addr.sa_family, SOCK_DGRAM, IPPROTO_UDP,
&ctx);
if (ret < 0) {
DBG("Cannot get context (%d)\n", ret);
return ret;
}
if (IS_ENABLED(CONFIG_NET_HOSTNAME_ENABLE)) {
memcpy(hostname, net_hostname_get(), MAX_HOSTNAME_LEN);
} else if (IS_ENABLED(CONFIG_NET_IPV6) &&
server_addr.sa_family == AF_INET6) {
const struct in6_addr *src;
src = net_if_ipv6_select_src_addr(
NULL, &net_sin6(&server_addr)->sin6_addr);
if (src) {
net_addr_ntop(AF_INET6, src, hostname,
MAX_HOSTNAME_LEN);
net_ipaddr_copy(&local_addr6.sin6_addr, src);
} else {
goto unknown;
}
} else if (IS_ENABLED(CONFIG_NET_IPV4) &&
server_addr.sa_family == AF_INET) {
struct net_if_ipv4 *ipv4;
struct net_if *iface;
iface = net_if_ipv4_select_src_iface(
&net_sin(&server_addr)->sin_addr);
ipv4 = iface->config.ip.ipv4;
net_ipaddr_copy(&local_addr4.sin_addr,
&ipv4->unicast[0].address.in_addr);
net_addr_ntop(AF_INET, &local_addr4.sin_addr, hostname,
MAX_HOSTNAME_LEN);
} else {
unknown:
DBG("Cannot setup local context\n");
return -EINVAL;
}
ret = net_context_bind(ctx, local_addr, server_addr_len);
if (ret < 0) {
DBG("Cannot bind context (%d)\n", ret);
return ret;
}
(void)net_context_connect(ctx, &server_addr, server_addr_len,
NULL, K_NO_WAIT, NULL);
/* We do not care about return value for this UDP connect call that
* basically does nothing. Calling the connect is only useful so that
* we can see the syslog connection in net-shell.
*/
net_context_setup_pools(ctx, get_tx_slab, get_data_pool);
log_output_ctx_set(&log_output, ctx);
log_output_hostname_set(&log_output, hostname);
return 0;
}
static void send_output(const struct log_backend *const backend,
struct log_msg *msg)
{
if (panic_mode) {
return;
}
if (!net_init_done) {
net_init_done = true;
if (do_net_init() < 0) {
net_init_done = false;
}
}
log_msg_get(msg);
log_output_msg_process(&log_output, msg,
LOG_OUTPUT_FLAG_FORMAT_SYSLOG |
LOG_OUTPUT_FLAG_TIMESTAMP);
log_msg_put(msg);
}
static void init_net(void)
{
int ret;
net_sin(&server_addr)->sin_port = htons(514);
ret = net_ipaddr_parse(CONFIG_LOG_BACKEND_NET_SERVER,
sizeof(CONFIG_LOG_BACKEND_NET_SERVER) - 1,
&server_addr);
if (!ret) {
LOG_ERR("Cannot configure syslog server address");
return;
}
log_backend_deactivate(log_backend_net_get());
}
static void panic(struct log_backend const *const backend)
{
panic_mode = true;
}
const struct log_backend_api log_backend_net_api = {
.put = send_output,
.panic = panic,
.init = init_net,
};
/* Note that the backend can be activated only after we have networking
* subsystem ready so we must not start it immediately.
*/
LOG_BACKEND_DEFINE(log_backend_net, log_backend_net_api, true);
const struct log_backend *log_backend_net_get(void)
{
return &log_backend_net;
}

View file

@ -6,8 +6,10 @@
#include <logging/log_output.h>
#include <logging/log_ctrl.h>
#include <logging/log.h>
#include <assert.h>
#include <ctype.h>
#include <time.h>
#define HEXDUMP_BYTES_IN_LINE 8
@ -46,6 +48,38 @@ extern int _prf(int (*func)(), void *dest, char *format, va_list vargs);
extern void _vprintk(out_func_t out, void *log_output,
const char *fmt, va_list ap);
/* The RFC 5424 allows very flexible mapping and suggest the value 0 being the
* highest severity and 7 to be the lowest (debugging level) severity.
*
* 0 Emergency System is unusable
* 1 Alert Action must be taken immediately
* 2 Critical Critical conditions
* 3 Error Error conditions
* 4 Warning Warning conditions
* 5 Notice Normal but significant condition
* 6 Informational Informational messages
* 7 Debug Debug-level messages
*/
static int level_to_rfc5424_severity(u32_t level)
{
switch (level) {
case LOG_LEVEL_NONE:
return 7;
case LOG_LEVEL_ERR:
return 3;
case LOG_LEVEL_WRN:
return 4;
case LOG_LEVEL_INF:
return 6;
case LOG_LEVEL_DBG:
return 7;
default:
break;
}
return 7;
}
static int out_func(int c, void *ctx)
{
const struct log_output *out_ctx =
@ -98,10 +132,14 @@ void log_output_flush(const struct log_output *log_output)
static int timestamp_print(struct log_msg *msg,
const struct log_output *log_output,
bool format)
u32_t flags)
{
int length;
u32_t timestamp = log_msg_timestamp_get(msg);
bool format =
(flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP) |
(flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG);
if (!format) {
length = print_formatted(log_output, "[%08lu] ", timestamp);
@ -124,9 +162,30 @@ static int timestamp_print(struct log_msg *msg,
ms = (remainder * 1000) / freq;
us = (1000 * (1000 * remainder - (ms * freq))) / freq;
if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
#if defined(CONFIG_NEWLIB_LIBC)
char time_str[sizeof("1970-01-01T00:00:00")];
struct tm *tm;
time_t time;
time = seconds;
tm = gmtime(&time);
strftime(time_str, sizeof(time_str), "%FT%T", tm);
length = print_formatted(log_output, "%s.%06dZ ",
time_str, ms * 1000 + us);
#else
length = print_formatted(log_output,
"1970-01-01T%02d:%02d:%02d.%06dZ ",
hours, mins, seconds, ms * 1000 + us);
#endif
} else {
length = print_formatted(log_output,
"[%02d:%02d:%02d.%03d,%03d] ",
hours, mins, seconds, ms, us);
}
} else {
length = 0;
}
@ -188,6 +247,10 @@ static int ids_print(struct log_msg *msg,
static void newline_print(const struct log_output *ctx, u32_t flags)
{
if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
return;
}
if (flags & LOG_OUTPUT_FLAG_CRLF_NONE) {
return;
@ -391,17 +454,40 @@ static int prefix_print(struct log_msg *msg,
bool colors_on = flags & LOG_OUTPUT_FLAG_COLORS;
bool level_on = flags & LOG_OUTPUT_FLAG_LEVEL;
if (stamp) {
bool stamp_format =
flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
/* TODO: As there is no way to figure out the
* facility at this point, use a pre-defined value.
* Change this to use the real facility of the
* logging call when that info is available.
*/
static const int facility = 16; /* local0 */
length += timestamp_print(msg, log_output,
stamp_format);
length += print_formatted(
log_output,
"<%d>1 ",
facility * 8 +
level_to_rfc5424_severity(
log_msg_level_get(msg)));
}
if (stamp) {
length += timestamp_print(msg, log_output, flags);
}
if (IS_ENABLED(CONFIG_LOG_BACKEND_NET) &&
flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) {
length += print_formatted(
log_output, "%s - - - - ",
log_output->control_block->hostname ?
log_output->control_block->hostname :
"zephyr");
} else {
color_prefix(msg, log_output, colors_on);
length += ids_print(msg, log_output, level_on);
}
}
return length;
}