Skip to content

Instantly share code, notes, and snippets.

@sjlongland
Created Dec 21, 2017
Embed
What would you like to do?
syslogd implementation for OpenThread

RFC 5424 compatible syslog implementation for OpenThread.

This requires:

  • a filesystem of some kind, with stubs for newlib's file I/O functions… we're using SPIFFS with a SPI EEPROM, but there are lots of options.
  • a real-time clock with an implementation of gettimeofday… we use a NXP PCF8523 I²C RTC to synchronise a software counter

If sending of a message fails (because buffers are full) and the message severity is high enough, the message is buffered to a file in the EEPROM and will be sent later when comms recovers. Otherwise it tries to send the message straight away. iprintf-compatible formatting is possible on messages.

/* vim: set tw=78 ts=8 noet si: */
/*!
* VRT WideSky Hub Demo Firmware System Logger
* (C) 2017 VRT Systems
*/
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include "hostname.h"
#include "syslog.h"
#include "fs.h"
#include <stdlib.h>
#include <sys/time.h>
#include <time.h>
#include <errno.h>
#include <stdarg.h>
#include <openthread/ip6.h>
#include <openthread/udp.h>
#include <openthread/thread.h>
#include <openthread/openthread.h>
#define SYSLOG_BUF_SZ (512)
#define SYSLOG_CFG "syslog.cfg"
#define LOGFILE_PRI "logfile.1"
#define LOGFILE_SEC "logfile.2"
#define SYSLOG_INIT_DELAY (5)
#define SYSLOG_NETWORK_DELAY (10)
#define SYSLOG_CHECK_DELAY (60)
#define SYSLOG_MAX_BUFFER_USE_PERCENT (10)
#define SYSLOG_PERSIST_SEVERITY (4)
/*!
* System logger re-sender file descriptor.
*/
static int syslog_resend_fd;
/*!
* System logger timer.
*/
static uint8_t syslog_timer;
/*!
* Configuration data
*/
struct syslog_config_t {
/*! Destination IP and port */
otSockAddr sockaddr;
/*! TTL for outgoing messages */
uint8_t ttl;
};
/*!
* Configuration
*/
static struct syslog_config_t syslog_config;
/*!
* Socket used for syslog traffic.
*/
static otUdpSocket syslog_socket;
/*!
* Format a received message into a log buffer and return its size.
*/
static int16_t syslog_format(
otInstance* instance,
char* buffer, uint16_t buf_sz,
time_t timestamp, uint8_t facility, uint8_t severity,
const char* app, const char* fmt, va_list fmt_args) {
/* Sum of bytes written */
int16_t sum = 0;
/* Converted timestamp */
struct tm tm;
if (!gmtime_r(&timestamp, &tm)) {
/* Invalid timestamp arguments given */
return -errno;
}
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Format message %s\r\n",
__FILE__, __LINE__, fmt);
#endif
#endif
/* Format the message header first. */
int fmt_sz = sniprintf(buffer, buf_sz,
"<%d>1 %04d-%02d-%02dT%02d:%02d:%02dZ ",
/* Priority value */
(facility << 3) | (severity & 0x07),
/* Timestamp */
tm.tm_year + 1900,
tm.tm_mon + 1,
tm.tm_mday,
tm.tm_hour,
tm.tm_min,
tm.tm_sec);
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Size: %d Buffer: %s\r\n",
__FILE__, __LINE__, fmt_sz, buffer);
#endif
#endif
buf_sz -= fmt_sz;
buffer += fmt_sz;
sum += fmt_sz;
/* Append hostname */
hostname(instance, buffer, buf_sz);
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Size: %d Buffer: %s\r\n",
__FILE__, __LINE__, HOSTNAME_LEN, buffer);
#endif
#endif
buffer += HOSTNAME_LEN;
buf_sz -= HOSTNAME_LEN;
sum += HOSTNAME_LEN;
/* Append remainder of header */
fmt_sz = sniprintf(buffer, buf_sz,
" %s - - - ", app);
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Size: %d Buffer: %s\r\n",
__FILE__, __LINE__, fmt_sz, buffer);
#endif
#endif
buffer += fmt_sz;
buf_sz -= fmt_sz;
sum += fmt_sz;
/* Append message */
fmt_sz = vsniprintf(buffer, buf_sz, fmt, fmt_args);
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Size: %d Buffer: %s\r\n",
__FILE__, __LINE__, fmt_sz, buffer);
#endif
#endif
sum += fmt_sz;
/* We're done */
#ifdef SYSLOG_TRACE
#ifdef SYSLOG_TRACE_FORMAT
iprintf("%s:%d Total %u\r\n",
__FILE__, __LINE__, sum);
#endif
#endif
return sum;
}
/*!
* Append a log message to a file for later transmission.
*/
static int16_t syslog_write(const char* log_msg, uint16_t msg_len) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d write %s\r\n", __FILE__, __LINE__, log_msg);
#endif
int fd = open((syslog_resend_fd > 0) ? LOGFILE_SEC : LOGFILE_PRI,
O_CREAT|O_APPEND|O_WRONLY);
if (fd < 0) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d Open fails with %s\r\n",
__FILE__, __LINE__, strerror(errno));
#endif
return -errno;
}
int sz = write(fd, &msg_len, sizeof(msg_len));
if (sz != sizeof(msg_len)) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d Write length fails with %s\r\n",
__FILE__, __LINE__, strerror(errno));
#endif
close(fd);
return -errno;
}
sz = write(fd, log_msg, msg_len);
close(fd);
if (sz != (int)msg_len) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d Write message fails with %s\r\n",
__FILE__, __LINE__, strerror(errno));
#endif
return -errno;
}
return 0;
}
/*!
* Submit a log message immediately.
*/
static otError syslog_tx(otInstance* instance,
const char* log_msg, uint16_t msg_len) {
otMessageInfo msg_info;
if (!syslog_socket.mHandler) {
return OT_ERROR_INVALID_STATE;
}
otError err = OT_ERROR_NONE;
memset(&msg_info, 0, sizeof(msg_info));
memcpy(&msg_info.mPeerAddr, &syslog_config.sockaddr.mAddress,
sizeof(otIp6Address));
msg_info.mPeerPort = syslog_config.sockaddr.mPort;
msg_info.mHopLimit = syslog_config.ttl;
msg_info.mInterfaceId = OT_NETIF_INTERFACE_ID_THREAD;
#ifdef SYSLOG_TRACE
iprintf("%s:%d tx %s\r\n", __FILE__, __LINE__, log_msg);
#endif
otMessage* msg = otUdpNewMessage(instance, true);
if (msg) {
err = otMessageAppend(msg, log_msg, msg_len);
} else {
err = OT_ERROR_NO_BUFS;
}
if (err == OT_ERROR_NONE) {
err = otUdpSend(&syslog_socket, msg, &msg_info);
}
if (msg && (err != OT_ERROR_NONE)) {
otMessageFree(msg);
}
#ifdef SYSLOG_TRACE
iprintf("%s:%d res %s\r\n", __FILE__, __LINE__, otThreadErrorToString(err));
#endif
return err;
}
/*!
* Read the system logger configuration.
*/
static int syslog_cfg_read() {
/* Try to read the syslog configuration */
int fd = open(SYSLOG_CFG, O_RDONLY);
if (fd >= 0) {
int res = read(fd, &syslog_config,
sizeof(syslog_config));
if (res < (int)sizeof(syslog_config)) {
res = -errno;
}
close(fd);
return res;
} else {
return -errno;
}
}
/*!
* Close any existing socket
*/
static void syslog_close() {
if (syslog_socket.mHandler) {
otUdpClose(&syslog_socket);
memset(&syslog_socket, 0, sizeof(syslog_socket));
}
}
/*!
* What to do on receipt of a UDP frame? Ignore it!
*/
static void syslog_recv(void *aContext, otMessage *aMessage,
const otMessageInfo *aMessageInfo) {
(void)aContext;
(void)aMessage;
(void)aMessageInfo;
}
/*!
* Open a new socket
*/
static int syslog_open(otInstance* instance) {
otError err = otUdpOpen(instance, &syslog_socket,
&syslog_recv, NULL);
#ifdef SYSLOG_TRACE
iprintf("%s:%d udpOpen = %d\r\n", __FILE__, __LINE__, err);
#endif
switch (err) {
case OT_ERROR_INVALID_ARGS:
return -EINVAL;
case OT_ERROR_NONE:
break;
default:
return -EIO;
}
err = otUdpConnect(&syslog_socket, &syslog_config.sockaddr);
#ifdef SYSLOG_TRACE
iprintf("%s:%d udpConnect = %d\r\n", __FILE__, __LINE__, err);
#endif
switch (err) {
case OT_ERROR_INVALID_ARGS:
return -EINVAL;
case OT_ERROR_NONE:
break;
default:
return -EIO;
}
return 0;
}
/*!
* Initialise the system logger interface.
*/
int syslog_init(otInstance* instance) {
syslog_resend_fd = -1;
syslog_timer = SYSLOG_INIT_DELAY;
if (syslog_cfg_read() < 0) {
return syslog_set_endpoint(instance, "ff02::1", 514, 1);
} else {
return syslog_open(instance);
}
}
/*!
* Set the endpoint for log messages.
*/
int syslog_set_endpoint(otInstance* instance, const char* target_ip,
uint16_t target_port, uint8_t ttl) {
syslog_close();
otSockAddr sockaddr;
memset(&sockaddr, 0, sizeof(sockaddr));
/* Parse the IP address */
otError err = otIp6AddressFromString(target_ip, &sockaddr.mAddress);
if (err != OT_ERROR_NONE) {
return -EINVAL;
}
/* Set the message target */
sockaddr.mPort = target_port;
memcpy(&syslog_config.sockaddr, &sockaddr, sizeof(sockaddr));
syslog_config.ttl = ttl;
int res = syslog_open(instance);
if (!res) {
int fd = open(SYSLOG_CFG, O_WRONLY);
if (fd < 0) {
return -errno;
}
res = write(fd, &syslog_config, sizeof(syslog_config));
if (res < (int)sizeof(syslog_config)) {
res = -errno;
}
close(fd);
}
return res;
}
/*!
* Process the stored log messages in our EEPROM logs.
*/
void syslog_process(otInstance* instance) {
if (syslog_timer) {
syslog_timer--;
return;
}
/* Check that we have a network */
switch (otThreadGetDeviceRole(instance)) {
case OT_DEVICE_ROLE_CHILD:
case OT_DEVICE_ROLE_ROUTER:
case OT_DEVICE_ROLE_LEADER:
break;
default:
/* No network */
syslog_timer = SYSLOG_NETWORK_DELAY;
return;
}
if (syslog_resend_fd <= 0) {
/* Check for written log messages to send */
syslog_resend_fd = open(LOGFILE_PRI, O_RDONLY);
if (syslog_resend_fd < 0) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d Unable to open log file: %s\r\n",
__FILE__, __LINE__, strerror(errno));
#endif
/*
* Rename the secondary to the
* primary, if it exists. Ignore if it doesn't.
*/
fs_rename(LOGFILE_SEC, LOGFILE_PRI);
/* Wait before retrying */
syslog_timer = SYSLOG_CHECK_DELAY;
return;
}
#ifdef SYSLOG_TRACE
iprintf("%s:%d Log file opened.\r\n",
__FILE__, __LINE__);
#endif
}
if (syslog_resend_fd) {
/*
* We have a log file open. Read the next message and
* send it if we can. Is there buffer space?
*/
otBufferInfo buffer_info;
otMessageGetBufferInfo(instance, &buffer_info);
uint32_t buffer_usage = buffer_info.mTotalBuffers
- buffer_info.mFreeBuffers;
buffer_usage *= 100;
buffer_usage /= buffer_info.mTotalBuffers;
if (buffer_usage > SYSLOG_MAX_BUFFER_USE_PERCENT) {
/* Do nothing for now */
syslog_timer = SYSLOG_NETWORK_DELAY;
return;
}
/* We have buffer space, and a network. */
int16_t msg_len;
int res = read(syslog_resend_fd, &msg_len, sizeof(msg_len));
if ((res != sizeof(msg_len)) || (msg_len < 26) || (msg_len > 2048)) {
/* Bad read… assume file is corrupt or end of file */
close(syslog_resend_fd);
syslog_resend_fd = -1;
fs_remove(LOGFILE_PRI);
#ifdef SYSLOG_TRACE
iprintf("%s:%d Log file closed.\r\n",
__FILE__, __LINE__);
#endif
return;
}
/* Read the message to be sent */
char msg[msg_len+1];
res = read(syslog_resend_fd, msg, msg_len);
msg[msg_len] = 0;
if (res != msg_len) {
/* Bad read… assume file is corrupt or end of file */
close(syslog_resend_fd);
syslog_resend_fd = -1;
fs_remove(LOGFILE_PRI);
#ifdef SYSLOG_TRACE
iprintf("%s:%d Log file closed.\r\n",
__FILE__, __LINE__);
#endif
return;
}
#ifdef SYSLOG_TRACE
iprintf("%s:%d Read stored message: %s\r\n",
__FILE__, __LINE__, msg);
#endif
/* We have read the message in… send it */
otError err = syslog_tx(instance, msg, msg_len);
if (err != OT_ERROR_NONE) {
#ifdef SYSLOG_TRACE
iprintf("%s:%d Send failed: %s\r\n",
__FILE__, __LINE__, msg);
#endif
/* Failed. Re-wind to try again. */
lseek(syslog_resend_fd,
-msg_len - sizeof(msg_len), SEEK_CUR);
}
}
}
/*!
* Send a syslog message.
*/
int syslog_send_va(otInstance* instance,
uint8_t facility, uint8_t severity,
const char* app, const char* fmt, va_list fmt_args) {
/* Retrieve the current system time */
struct timeval tv;
int res = gettimeofday(&tv, NULL);
if (res < 0) {
return res;
}
char buffer[SYSLOG_BUF_SZ];
int16_t sz = syslog_format(instance, buffer, sizeof(buffer),
tv.tv_sec, facility, severity, app, fmt, fmt_args);
if (sz < 0) {
return sz;
}
/* Try to send the message */
#ifdef SYSLOG_TRACE
iprintf("%s:%d msg %s\r\n", __FILE__, __LINE__, buffer);
#endif
otError err = syslog_tx(instance, buffer, sz);
if ((err != OT_ERROR_NONE) && (severity <= SYSLOG_PERSIST_SEVERITY)) {
/* Try to persist it for later */
res = syslog_write(buffer, sz);
}
return res;
}
/* vim: set tw=78 sw=8 ts=8 noet: */
/*!
* VRT WideSky Hub System Log
* (C) 2017 VRT Systems
*/
#ifndef SYSLOG_H_
#define SYSLOG_H_
#ifdef __cplusplus
extern "C" {
#endif
#include <string.h>
#include <stdbool.h>
#include <stdint.h>
#include <stdarg.h>
#include <openthread/types.h>
#include <openthread/ip6.h>
#include <openthread/udp.h>
/* Syslog message facilities */
#define SYSLOG_FAC_KERNEL (0) /*!< kernel messages */
#define SYSLOG_FAC_USER (1) /*!< user-level messages */
#define SYSLOG_FAC_MAIL (2) /*!< mail system */
#define SYSLOG_FAC_SYSTEM (3) /*!< system daemons */
#define SYSLOG_FAC_SECURITY (4) /*!< security/authorization messages */
#define SYSLOG_FAC_SYSLOGD (5) /*!< messages generated by syslogd */
#define SYSLOG_FAC_LP (6) /*!< line printer subsystem */
#define SYSLOG_FAC_NETNEWS (7) /*!< network news subsystem */
#define SYSLOG_FAC_UUCP (8) /*!< UUCP subsystem */
#define SYSLOG_FAC_CLOCK (9) /*!< clock daemon */
#define SYSLOG_FAC_SECURITY2 (10) /*!< security/authorization messages */
#define SYSLOG_FAC_FTP (11) /*!< FTP daemon */
#define SYSLOG_FAC_NTP (12) /*!< NTP subsystem */
#define SYSLOG_FAC_AUDIT (13) /*!< log audit */
#define SYSLOG_FAC_ALERT (14) /*!< log alert */
#define SYSLOG_FAC_CLOCKD (15) /*!< clock daemon */
#define SYSLOG_FAC_LOCAL0 (16) /*!< local use 0 (local0) */
#define SYSLOG_FAC_LOCAL1 (17) /*!< local use 1 (local1) */
#define SYSLOG_FAC_LOCAL2 (18) /*!< local use 2 (local2) */
#define SYSLOG_FAC_LOCAL3 (19) /*!< local use 3 (local3) */
#define SYSLOG_FAC_LOCAL4 (20) /*!< local use 4 (local4) */
#define SYSLOG_FAC_LOCAL5 (21) /*!< local use 5 (local5) */
#define SYSLOG_FAC_LOCAL6 (22) /*!< local use 6 (local6) */
#define SYSLOG_FAC_LOCAL7 (23) /*!< local use 7 (local7) */
/* Syslog message severities */
#define SYSLOG_SEV_EMERGENCY (0) /*!< Emergency: system is unusable */
#define SYSLOG_SEV_ALERT (1) /*!< Alert: action must be taken immediately */
#define SYSLOG_SEV_CRITICAL (2) /*!< Critical: critical conditions */
#define SYSLOG_SEV_ERROR (3) /*!< Error: error conditions */
#define SYSLOG_SEV_WARNING (4) /*!< Warning: warning conditions */
#define SYSLOG_SEV_NOTICE (5) /*!< Notice: normal but significant condition */
#define SYSLOG_SEV_INFO (6) /*!< Informational: informational messages */
#define SYSLOG_SEV_DEBUG (7) /*!< Debug: debug-level messages */
/*!
* Initialise the system logger interface.
*/
int syslog_init(otInstance* instance);
/*!
* Set the endpoint for log messages.
*/
int syslog_set_endpoint(otInstance* instance, const char* target_ip,
uint16_t target_port, uint8_t ttl);
/*!
* Process the stored log messages in our EEPROM logs.
*/
void syslog_process(otInstance* instance);
/*!
* Send a syslog message.
*/
int syslog_send_va(otInstance* instance,
uint8_t facility, uint8_t severity,
const char* app, const char* fmt, va_list fmt_args);
/*!
* Send a syslog message (varadic version).
*/
static inline int syslog_send(otInstance* instance,
uint8_t facility, uint8_t severity,
const char* app, const char* fmt, ...) {
int res;
va_list fmt_args;
va_start(fmt_args, fmt);
res = syslog_send_va(instance, facility, severity, app, fmt, fmt_args);
va_end(fmt_args);
return res;
}
#ifdef __cplusplus
} // end extern "C"
#endif
#endif
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment