mirror_frr/lib/zlog_5424.c
David Lamparter 1c6261a99e lib: RFC5424 & journald extended syslog target
Not much to say here, user docs are coming up in a separate commit.
RFC5424 and (systemd's) journald allow passing structured key-value
data.  This stuffs the metadata we have available into there.

The "does the system syslogd support RFC5424" question is unfortunately
not easily answered, so we can only give an affirmative answer on NetBSD
5.0+ or FreeBSD 12+.

Signed-off-by: David Lamparter <equinox@opensourcerouting.org>
2022-01-17 00:39:00 +01:00

1147 lines
28 KiB
C

/*
* Copyright (c) 2015-21 David Lamparter, for NetDEF, Inc.
*
* Permission to use, copy, modify, and distribute this software for any
* purpose with or without fee is hereby granted, provided that the above
* copyright notice and this permission notice appear in all copies.
*
* THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
* WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
* MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
* ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
* WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
* ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
* OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
*/
/* when you work on this code, please install a fuzzer (e.g. AFL) and run
* tests/lib/fuzz_zlog.c
*
* The most likely type of bug in this code is an off-by-one error in the
* buffer management pieces, and this isn't easily covered by an unit test
* or topotests. Fuzzing is the best tool here, but the CI can't do that
* since it's quite resource intensive.
*/
#include "zebra.h"
#include "zlog_5424.h"
#include <sys/un.h>
#include <syslog.h>
#include "memory.h"
#include "frrcu.h"
#include "printfrr.h"
#include "typerb.h"
#include "frr_pthread.h"
#include "command.h"
#include "monotime.h"
#include "thread.h"
#include "lib/version.h"
#include "lib/lib_errors.h"
DEFINE_MTYPE_STATIC(LOG, LOG_5424, "extended log target");
DEFINE_MTYPE_STATIC(LOG, LOG_5424_ROTATE, "extended log rotate helper");
/* the actual log target data structure
*
* remember this is RCU'd by the core zlog functions. Changing anything
* works by allocating a new struct, filling it, adding it, and removing the
* old one.
*/
struct zlt_5424 {
struct zlog_target zt;
atomic_uint_fast32_t fd;
enum zlog_5424_format fmt;
uint32_t ts_flags;
int facility;
/* the various extra pieces to add... */
bool kw_version : 1;
bool kw_location : 1;
bool kw_uid : 1;
bool kw_ec : 1;
bool kw_args : 1;
/* some formats may or may not include the trailing \n */
bool use_nl : 1;
/* for DGRAM & SEQPACKET sockets, send 1 log message per packet, since
* the socket preserves packet boundaries. On Linux, this uses
* sendmmsg() for efficiency, on other systems we need a syscall each.
*/
bool packets : 1;
/* for DGRAM, in order to not have to reconnect, we need to use
* sendto()/sendmsg() with the destination given; otherwise we'll get
* ENOTCONN. (We do a connect(), which serves to verify the type of
* socket, but if the receiver goes away, the kernel disconnects the
* socket so writev() no longer works since the destination is now
* unspecified.)
*/
struct sockaddr_storage sa;
socklen_t sa_len;
/* these are both getting set, but current_err is cleared on success,
* so we know whether the error is current or past.
*/
int last_err, current_err;
atomic_size_t lost_msgs;
struct timeval last_err_ts;
struct rcu_head_close head_close;
};
static int zlog_5424_open(struct zlog_cfg_5424 *zcf, int sock_type);
/* rough header length estimate
* ============================
*
* ^ = might grow
*
* 49^ longest filename (pceplib/test/pcep_utils_double_linked_list_test.h)
* 5^ highest line number (48530, bgpd/bgp_nb_config.c)
* 65^ longest function name
* (lib_prefix_list_entry_ipv6_prefix_length_greater_or_equal_destroy)
* 11 unique id ("XXXXX-XXXXX")
* 10 EC ("4294967295" or "0xffffffff")
* 35 ISO8601 TS at full length ("YYYY-MM-DD HH:MM:SS.NNNNNNNNN+ZZ:ZZ")
* ---
* 175
*
* rarely used (hopefully...):
* 26^ FRR_VERSION ("10.10.10-dev-gffffffffffff")
* ---
* 201
*
* x16 highest number of format parameters currently
* 40 estimate for hostname + 2*daemon + pid
*
* specific format overhead:
*
* RFC3164 - shorter than the others
* RFC5424 - 175 + "<999>1 "=7 + 52 (location@50145) + 40 (host/...)
* rarely: + 65 + 26 (for [origin])
* args: 16 * (8 + per-arg (20?)) = ~448
*
* so without "args@", origin or (future) keywords, around 256 seems OK
* with args@ and/or origin and/or keywords, 512 seems more reasonable
*
* but - note the code allocates this amount multiplied by the number of
* messages in the incoming batch (minimum 3), this means short messages and
* long messages smooth each other out.
*
* Since the code handles space-exceeded by grabbing a bunch of stack memory,
* a reasonable middle ground estimate is desirable here, so ...
* *drumroll*
* let's go with 128 + args?128. (remember the minimum 3 multiplier)
*
* low_space is the point where we don't try to fit another message in & just
* submit what we have to the kernel.
*
* The zlog code only buffers debug & informational messages, so in production
* usage most of the calls will be writing out only 1 message. This makes
* the min *3 multiplier quite useful.
*/
static inline size_t zlog_5424_bufsz(struct zlt_5424 *zte, size_t nmsgs,
size_t *low_space)
{
size_t ret = 128;
if (zte->kw_args)
ret += 128;
*low_space = ret;
return ret * MAX(nmsgs, 3);
}
struct state {
struct fbuf *fbuf;
struct iovec *iov;
};
/* stack-based keyword support is likely to bump this to 3 or 4 */
#define IOV_PER_MSG 2
_Static_assert(IOV_MAX >= IOV_PER_MSG,
"this code won't work with IOV_MAX < IOV_PER_MSG");
/* the following functions are quite similar, but trying to merge them just
* makes a big mess. check the others when touching one.
*
* timestamp keywords hostname
* RFC5424 ISO8601 yes yes
* RFC3164 RFC3164 no yes
* local RFC3164 no no
* journald ISO8601(unused) yes (unused)
*/
static size_t zlog_5424_one(struct zlt_5424 *zte, struct zlog_msg *msg,
struct state *state)
{
size_t textlen;
struct fbuf *fbuf = state->fbuf;
char *orig_pos = fbuf->pos;
size_t need = 0;
int prio = zlog_msg_prio(msg);
intmax_t pid, tid;
zlog_msg_pid(msg, &pid, &tid);
need += bprintfrr(fbuf, "<%d>1 ", prio | zte->facility);
need += zlog_msg_ts(msg, fbuf, zte->ts_flags);
need += bprintfrr(fbuf, " %s %s %jd %.*s ", cmd_hostname_get() ?: "-",
zlog_progname, pid, (int)(zlog_prefixsz - 2),
zlog_prefix);
if (zte->kw_version)
need += bprintfrr(
fbuf,
"[origin enterpriseId=\"50145\" software=\"FRRouting\" swVersion=\"%s\"]",
FRR_VERSION);
const struct xref_logmsg *xref;
struct xrefdata *xrefdata;
need += bprintfrr(fbuf, "[location@50145 tid=\"%jd\"", tid);
if (zlog_instance > 0)
need += bprintfrr(fbuf, " instance=\"%d\"", zlog_instance);
xref = zlog_msg_xref(msg);
xrefdata = xref ? xref->xref.xrefdata : NULL;
if (xrefdata) {
if (zte->kw_uid)
need += bprintfrr(fbuf, " id=\"%s\"", xrefdata->uid);
if (zte->kw_ec && prio <= LOG_WARNING)
need += bprintfrr(fbuf, " ec=\"%u\"", xref->ec);
if (zte->kw_location)
need += bprintfrr(
fbuf, " file=\"%s\" line=\"%d\" func=\"%s\"",
xref->xref.file, xref->xref.line,
xref->xref.func);
}
need += bputch(fbuf, ']');
size_t hdrlen, n_argpos;
const struct fmt_outpos *argpos;
const char *text;
text = zlog_msg_text(msg, &textlen);
zlog_msg_args(msg, &hdrlen, &n_argpos, &argpos);
if (zte->kw_args && n_argpos) {
need += bputs(fbuf, "[args@50145");
for (size_t i = 0; i < n_argpos; i++) {
int len = argpos[i].off_end - argpos[i].off_start;
need += bprintfrr(fbuf, " arg%zu=%*pSQsq", i + 1, len,
text + argpos[i].off_start);
}
need += bputch(fbuf, ']');
}
need += bputch(fbuf, ' ');
if (orig_pos + need > fbuf->buf + fbuf->len) {
/* not enough space in the buffer for headers. the loop in
* zlog_5424() will flush other messages that are already in
* the buffer, grab a bigger buffer if needed, and try again.
*/
fbuf->pos = orig_pos;
return need;
}
/* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
state->iov->iov_base = orig_pos;
state->iov->iov_len = fbuf->pos - orig_pos;
state->iov++;
state->iov->iov_base = (char *)text + hdrlen;
state->iov->iov_len = textlen - hdrlen + zte->use_nl;
state->iov++;
return 0;
}
static size_t zlog_3164_one(struct zlt_5424 *zte, struct zlog_msg *msg,
struct state *state)
{
size_t textlen;
struct fbuf *fbuf = state->fbuf;
char *orig_pos = fbuf->pos;
size_t need = 0;
int prio = zlog_msg_prio(msg);
intmax_t pid, tid;
zlog_msg_pid(msg, &pid, &tid);
need += bprintfrr(fbuf, "<%d>", prio | zte->facility);
need += zlog_msg_ts_3164(msg, fbuf, zte->ts_flags);
if (zte->fmt != ZLOG_FMT_LOCAL) {
need += bputch(fbuf, ' ');
need += bputs(fbuf, cmd_hostname_get() ?: "-");
}
need += bprintfrr(fbuf, " %s[%jd]: ", zlog_progname, pid);
if (orig_pos + need > fbuf->buf + fbuf->len) {
/* not enough space in the buffer for headers. loop in
* zlog_5424() will flush other messages that are already in
* the buffer, grab a bigger buffer if needed, and try again.
*/
fbuf->pos = orig_pos;
return need;
}
/* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
state->iov->iov_base = orig_pos;
state->iov->iov_len = fbuf->pos - orig_pos;
state->iov++;
state->iov->iov_base = (char *)zlog_msg_text(msg, &textlen);
state->iov->iov_len = textlen + zte->use_nl;
state->iov++;
return 0;
}
static size_t zlog_journald_one(struct zlt_5424 *zte, struct zlog_msg *msg,
struct state *state)
{
size_t textlen;
struct fbuf *fbuf = state->fbuf;
char *orig_pos = fbuf->pos;
size_t need = 0;
int prio = zlog_msg_prio(msg);
intmax_t pid, tid;
zlog_msg_pid(msg, &pid, &tid);
need += bprintfrr(fbuf,
"PRIORITY=%d\n"
"SYSLOG_FACILITY=%d\n"
"TID=%jd\n"
"FRR_DAEMON=%s\n"
"SYSLOG_TIMESTAMP=",
prio, zte->facility, tid, zlog_progname);
need += zlog_msg_ts(msg, fbuf, zte->ts_flags);
need += bputch(fbuf, '\n');
if (zlog_instance > 0)
need += bprintfrr(fbuf, "FRR_INSTANCE=%d\n", zlog_instance);
const struct xref_logmsg *xref;
struct xrefdata *xrefdata;
xref = zlog_msg_xref(msg);
xrefdata = xref ? xref->xref.xrefdata : NULL;
if (xrefdata) {
if (zte->kw_uid && xrefdata->uid[0])
need += bprintfrr(fbuf, "FRR_ID=%s\n", xrefdata->uid);
if (zte->kw_ec && prio <= LOG_WARNING)
need += bprintfrr(fbuf, "FRR_EC=%d\n", xref->ec);
if (zte->kw_location)
need += bprintfrr(fbuf,
"CODE_FILE=%s\n"
"CODE_LINE=%d\n"
"CODE_FUNC=%s\n",
xref->xref.file, xref->xref.line,
xref->xref.func);
}
size_t hdrlen, n_argpos;
const struct fmt_outpos *argpos;
const char *text;
text = zlog_msg_text(msg, &textlen);
zlog_msg_args(msg, &hdrlen, &n_argpos, &argpos);
if (zte->kw_args && n_argpos) {
for (size_t i = 0; i < n_argpos; i++) {
int len = argpos[i].off_end - argpos[i].off_start;
/* rather than escape the value, we could use
* journald's binary encoding, but that seems a bit
* excessive/unnecessary. 99% of things we print here
* will just output 1:1 with %pSE.
*/
need += bprintfrr(fbuf, "FRR_ARG%zu=%*pSE\n", i + 1,
len, text + argpos[i].off_start);
}
}
need += bputs(fbuf, "MESSAGE=");
if (orig_pos + need > fbuf->buf + fbuf->len) {
/* not enough space in the buffer for headers. loop in
* zlog_5424() will flush other messages that are already in
* the buffer, grab a bigger buffer if needed, and try again.
*/
fbuf->pos = orig_pos;
return need;
}
/* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
state->iov->iov_base = orig_pos;
state->iov->iov_len = fbuf->pos - orig_pos;
state->iov++;
state->iov->iov_base = (char *)text + hdrlen;
state->iov->iov_len = textlen - hdrlen + 1;
state->iov++;
return 0;
}
static size_t zlog_one(struct zlt_5424 *zte, struct zlog_msg *msg,
struct state *state)
{
switch (zte->fmt) {
case ZLOG_FMT_5424:
return zlog_5424_one(zte, msg, state);
case ZLOG_FMT_3164:
case ZLOG_FMT_LOCAL:
return zlog_3164_one(zte, msg, state);
case ZLOG_FMT_JOURNALD:
return zlog_journald_one(zte, msg, state);
}
return 0;
}
static void zlog_5424_err(struct zlt_5424 *zte, size_t count)
{
if (!count) {
zte->current_err = 0;
return;
}
/* only the counter is atomic because otherwise it'd be meaningless */
atomic_fetch_add_explicit(&zte->lost_msgs, count, memory_order_relaxed);
/* these are non-atomic and can provide wrong results when read, but
* since they're only for debugging / display, that's OK.
*/
zte->current_err = zte->last_err = errno;
monotime(&zte->last_err_ts);
}
static void zlog_5424(struct zlog_target *zt, struct zlog_msg *msgs[],
size_t nmsgs)
{
size_t i;
struct zlt_5424 *zte = container_of(zt, struct zlt_5424, zt);
int fd, ret;
size_t niov = MIN(IOV_PER_MSG * nmsgs, IOV_MAX);
struct iovec iov[niov], *iov_last = iov + niov;
struct mmsghdr mmsg[zte->packets ? nmsgs : 1], *mpos = mmsg;
size_t count = 0;
/* refer to size estimate at top of file */
size_t low_space;
char hdr_buf[zlog_5424_bufsz(zte, nmsgs, &low_space)];
struct fbuf hdr_pos = {
.buf = hdr_buf,
.pos = hdr_buf,
.len = sizeof(hdr_buf),
};
struct state state = {
.fbuf = &hdr_pos,
.iov = iov,
};
fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
memset(mmsg, 0, sizeof(mmsg));
if (zte->sa_len) {
for (i = 0; i < array_size(mmsg); i++) {
mmsg[i].msg_hdr.msg_name = (struct sockaddr *)&zte->sa;
mmsg[i].msg_hdr.msg_namelen = zte->sa_len;
}
}
mmsg[0].msg_hdr.msg_iov = iov;
for (i = 0; i < nmsgs; i++) {
int prio = zlog_msg_prio(msgs[i]);
size_t need = 0;
if (prio <= zte->zt.prio_min) {
if (zte->packets)
mpos->msg_hdr.msg_iov = state.iov;
need = zlog_one(zte, msgs[i], &state);
if (zte->packets) {
mpos->msg_hdr.msg_iovlen =
state.iov - mpos->msg_hdr.msg_iov;
mpos++;
}
count++;
}
/* clang-format off */
if ((need
|| (size_t)(hdr_pos.buf + hdr_pos.len - hdr_pos.pos)
< low_space
|| i + 1 == nmsgs
|| state.iov + IOV_PER_MSG > iov_last)
&& state.iov > iov) {
/* clang-format on */
if (zte->packets) {
struct mmsghdr *sendpos;
for (sendpos = mmsg; sendpos < mpos;) {
ret = sendmmsg(fd, sendpos,
mpos - sendpos, 0);
if (ret <= 0)
break;
sendpos += ret;
}
zlog_5424_err(zte, mpos - sendpos);
mpos = mmsg;
} else {
if (!zte->sa_len)
ret = writev(fd, iov, state.iov - iov);
else {
mpos->msg_hdr.msg_iovlen =
state.iov - iov;
ret = sendmsg(fd, &mpos->msg_hdr, 0);
}
if (ret < 0)
zlog_5424_err(zte, count);
else
zlog_5424_err(zte, 0);
}
count = 0;
hdr_pos.pos = hdr_buf;
state.iov = iov;
}
/* if need == 0, we just put a message (or nothing) in the
* buffer and are continuing for more to batch in a single
* writev()
*/
if (need == 0)
continue;
if (need && need <= sizeof(hdr_buf)) {
/* don't need to allocate, just try this msg
* again without other msgs already using up
* buffer space
*/
i--;
continue;
}
/* need > sizeof(hdr_buf), need to grab some memory. Taking
* it off the stack is fine here.
*/
char buf2[need];
struct fbuf fbuf2 = {
.buf = buf2,
.pos = buf2,
.len = sizeof(buf2),
};
state.fbuf = &fbuf2;
need = zlog_one(zte, msgs[i], &state);
assert(need == 0);
if (!zte->sa_len)
ret = writev(fd, iov, state.iov - iov);
else {
mpos->msg_hdr.msg_iovlen = state.iov - iov;
ret = sendmsg(fd, &mpos->msg_hdr, 0);
}
if (ret < 0)
zlog_5424_err(zte, 1);
else
zlog_5424_err(zte, 0);
count = 0;
state.fbuf = &hdr_pos;
state.iov = iov;
mpos = mmsg;
}
assert(state.iov == iov);
}
/* strftime(), gmtime_r() and localtime_r() aren't AS-Safe (they access locale
* data), but we need an AS-Safe timestamp below :(
*/
static void gmtime_assafe(time_t ts, struct tm *res)
{
res->tm_sec = ts % 60;
ts /= 60;
res->tm_min = ts % 60;
ts /= 60;
res->tm_hour = ts % 24;
ts /= 24;
ts -= 11017; /* start on 2020-03-01, 11017 days since 1970-01-01 */
/* 1461 days = 3 regular years + 1 leap year
* this works until 2100, which isn't a leap year
*
* struct tm.tm_year starts at 1900.
*/
res->tm_year = 2000 - 1900 + 4 * (ts / 1461);
ts = ts % 1461;
if (ts == 1460) {
res->tm_year += 4;
res->tm_mon = 1;
res->tm_mday = 29;
return;
}
res->tm_year += ts / 365;
ts %= 365;
/* note we're starting in march like the romans did... */
if (ts >= 306) /* Jan 1 of next year */
res->tm_year++;
static unsigned int months[13] = {
0, 31, 61, 92, 122, 153, 184, 214, 245, 275, 306, 337, 365,
};
for (size_t i = 0; i < array_size(months); i++) {
if ((unsigned int)ts < months[i + 1]) {
res->tm_mon = ((i + 2) % 12);
res->tm_mday = 1 + ts - months[i];
break;
}
}
}
/* one of the greatest advantages of this logging target: unlike syslog(),
* which is not AS-Safe, we can send crashlogs to syslog here.
*/
static void zlog_5424_sigsafe(struct zlog_target *zt, const char *text,
size_t len)
{
static const char *const months_3164[12] = {
"Jan", "Feb", "Mar", "Apr", "May", "Jun",
"Jul", "Aug", "Sep", "Oct", "Nov", "Dec",
};
struct zlt_5424 *zte = container_of(zt, struct zlt_5424, zt);
struct iovec iov[3], *iovp = iov;
char buf[256];
struct fbuf fbuf = {
.buf = buf,
.pos = buf,
.len = sizeof(buf),
};
int fd;
intmax_t pid = (intmax_t)getpid();
struct tm tm;
switch (zte->fmt) {
case ZLOG_FMT_5424:
gmtime_assafe(time(NULL), &tm);
bprintfrr(
&fbuf,
"<%d>1 %04u-%02u-%02uT%02u:%02u:%02uZ - %s %jd %.*s ",
zte->facility | LOG_CRIT, tm.tm_year + 1900,
tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min,
tm.tm_sec, zlog_progname, pid, (int)(zlog_prefixsz - 2),
zlog_prefix);
break;
case ZLOG_FMT_3164:
case ZLOG_FMT_LOCAL:
/* this will unfortuantely be wrong by the timezone offset
* if the user selected non-UTC. But not much we can do
* about that...
*/
gmtime_assafe(time(NULL), &tm);
bprintfrr(&fbuf, "<%d>%3s %2u %02u:%02u:%02u %s%s[%jd]: ",
zte->facility | LOG_CRIT, months_3164[tm.tm_mon],
tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
(zte->fmt == ZLOG_FMT_LOCAL) ? "" : "- ",
zlog_progname, pid);
break;
case ZLOG_FMT_JOURNALD:
bprintfrr(&fbuf,
"PRIORITY=%d\n"
"SYSLOG_FACILITY=%d\n"
"FRR_DAEMON=%s\n"
"MESSAGE=",
LOG_CRIT, zte->facility, zlog_progname);
break;
}
iovp->iov_base = fbuf.buf;
iovp->iov_len = fbuf.pos - fbuf.buf;
iovp++;
iovp->iov_base = (char *)text;
iovp->iov_len = len;
iovp++;
if (zte->use_nl) {
iovp->iov_base = (char *)"\n";
iovp->iov_len = 1;
iovp++;
}
fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
if (!zte->sa_len)
writev(fd, iov, iovp - iov);
else {
struct msghdr mh = {};
mh.msg_name = (struct sockaddr *)&zte->sa;
mh.msg_namelen = zte->sa_len;
mh.msg_iov = iov;
mh.msg_iovlen = iovp - iov;
sendmsg(fd, &mh, 0);
}
}
/* housekeeping & configuration */
void zlog_5424_init(struct zlog_cfg_5424 *zcf)
{
pthread_mutex_init(&zcf->cfg_mtx, NULL);
}
static void zlog_5424_target_free(struct zlt_5424 *zlt)
{
if (!zlt)
return;
rcu_close(&zlt->head_close, zlt->fd);
rcu_free(MTYPE_LOG_5424, zlt, zt.rcu_head);
}
void zlog_5424_fini(struct zlog_cfg_5424 *zcf, bool keepopen)
{
if (keepopen)
zcf->active = NULL;
if (zcf->active) {
struct zlt_5424 *ztf;
struct zlog_target *zt;
zt = zlog_target_replace(&zcf->active->zt, NULL);
ztf = container_of(zt, struct zlt_5424, zt);
zlog_5424_target_free(ztf);
}
pthread_mutex_destroy(&zcf->cfg_mtx);
}
static void zlog_5424_cycle(struct zlog_cfg_5424 *zcf, int fd)
{
struct zlog_target *old;
struct zlt_5424 *zlt = NULL, *oldt;
if (fd >= 0) {
struct zlog_target *zt;
/* all of this is swapped in by zlog_target_replace() below,
* the old target is RCU-freed afterwards.
*/
zt = zlog_target_clone(MTYPE_LOG_5424, &zcf->active->zt,
sizeof(*zlt));
zlt = container_of(zt, struct zlt_5424, zt);
zlt->fd = fd;
zlt->kw_version = zcf->kw_version;
zlt->kw_location = zcf->kw_location;
zlt->kw_uid = zcf->kw_uid;
zlt->kw_ec = zcf->kw_ec;
zlt->kw_args = zcf->kw_args;
zlt->use_nl = true;
zlt->facility = zcf->facility;
/* DGRAM & SEQPACKET = 1 log message per packet */
zlt->packets = (zcf->sock_type == SOCK_DGRAM) ||
(zcf->sock_type == SOCK_SEQPACKET);
zlt->sa = zcf->sa;
zlt->sa_len = zcf->sa_len;
zlt->fmt = zcf->fmt;
zlt->zt.prio_min = zcf->prio_min;
zlt->zt.logfn = zlog_5424;
zlt->zt.logfn_sigsafe = zlog_5424_sigsafe;
switch (zcf->fmt) {
case ZLOG_FMT_5424:
case ZLOG_FMT_JOURNALD:
zlt->ts_flags = zcf->ts_flags;
zlt->ts_flags &= ZLOG_TS_PREC | ZLOG_TS_UTC;
zlt->ts_flags |= ZLOG_TS_ISO8601;
break;
case ZLOG_FMT_3164:
case ZLOG_FMT_LOCAL:
zlt->ts_flags = zcf->ts_flags & ZLOG_TS_UTC;
if (zlt->packets)
zlt->use_nl = false;
break;
}
}
old = zcf->active ? &zcf->active->zt : NULL;
old = zlog_target_replace(old, &zlt->zt);
zcf->active = zlt;
/* oldt->fd == fd happens for zlog_5424_apply_meta() */
oldt = container_of(old, struct zlt_5424, zt);
if (oldt && oldt->fd != (unsigned int)fd)
rcu_close(&oldt->head_close, oldt->fd);
rcu_free(MTYPE_LOG_5424, oldt, zt.rcu_head);
}
static int zlog_5424_reconnect(struct thread *t)
{
struct zlog_cfg_5424 *zcf = THREAD_ARG(t);
int fd = THREAD_FD(t);
char dummy[256];
ssize_t ret;
if (zcf->active) {
ret = read(fd, dummy, sizeof(dummy));
if (ret > 0) {
/* logger is sending us something?!?! */
thread_add_read(t->master, zlog_5424_reconnect, zcf, fd,
&zcf->t_reconnect);
return 0;
}
if (ret == 0)
zlog_warn("logging socket %pSE closed by peer",
zcf->filename);
else
zlog_warn("logging socket %pSE error: %m",
zcf->filename);
}
/* do NOT close() anything here; other threads may still be writing
* and their messages need to be lost rather than end up on a random
* other fd that got reassigned the same number, like a BGP session!
*/
fd = zlog_5424_open(zcf, -1);
frr_with_mutex (&zcf->cfg_mtx) {
zlog_5424_cycle(zcf, fd);
}
return 0;
}
static int zlog_5424_unix(struct sockaddr_un *suna, int sock_type)
{
int fd;
int size = 1 * 1024 * 1024, prev_size;
socklen_t opt_size;
int save_errno;
fd = socket(AF_UNIX, sock_type, 0);
if (fd < 0)
return -1;
if (connect(fd, (struct sockaddr *)suna, sizeof(*suna))) {
/* zlog_5424_open() will print the error for connect() */
save_errno = errno;
close(fd);
errno = save_errno;
return -1;
}
opt_size = sizeof(prev_size);
if (getsockopt(fd, SOL_SOCKET, SO_SNDBUF, &prev_size, &opt_size))
return fd;
/* setsockopt_so_sendbuf() logs on error; we don't really care that
* much here. Also, never shrink the buffer below the initial size.
*/
while (size > prev_size &&
setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &size, sizeof(size)) == -1)
size /= 2;
return fd;
}
static int zlog_5424_open(struct zlog_cfg_5424 *zcf, int sock_type)
{
int fd = -1;
int flags = 0;
int err;
socklen_t optlen;
bool do_chown = false;
bool need_reconnect = false;
static const int unix_types[] = {
SOCK_STREAM,
SOCK_SEQPACKET,
SOCK_DGRAM,
};
struct sockaddr_un sa;
zcf->sock_type = -1;
zcf->sa_len = 0;
switch (zcf->dst) {
case ZLOG_5424_DST_NONE:
break;
case ZLOG_5424_DST_FD:
fd = dup(zcf->fd);
optlen = sizeof(sock_type);
if (!getsockopt(fd, SOL_SOCKET, SO_TYPE, &sock_type, &optlen)) {
zcf->sock_type = sock_type;
need_reconnect = (zcf->sock_type != SOCK_DGRAM);
}
break;
case ZLOG_5424_DST_FIFO:
if (!zcf->filename)
break;
if (!zcf->file_nocreate) {
frr_with_privs (lib_privs) {
mode_t prevmask;
prevmask = umask(0777 ^ zcf->file_mode);
err = mkfifo(zcf->filename, 0666);
umask(prevmask);
}
if (err == 0)
do_chown = true;
else if (errno != EEXIST)
break;
}
flags = O_NONBLOCK;
/* fallthru */
case ZLOG_5424_DST_FILE:
if (!zcf->filename)
break;
frr_with_privs (lib_privs) {
fd = open(zcf->filename, flags | O_WRONLY | O_APPEND |
O_CLOEXEC | O_NOCTTY);
}
if (fd >= 0)
break;
if (zcf->file_nocreate || flags) {
flog_err_sys(EC_LIB_SYSTEM_CALL,
"could not open log file %pSE: %m",
zcf->filename);
break;
}
frr_with_privs (lib_privs) {
mode_t prevmask;
prevmask = umask(0777 ^ zcf->file_mode);
fd = open(zcf->filename,
O_WRONLY | O_APPEND | O_CLOEXEC | O_NOCTTY |
O_CREAT | O_EXCL,
zcf->file_mode);
umask(prevmask);
}
if (fd >= 0) {
do_chown = true;
break;
}
frr_with_privs (lib_privs) {
fd = open(zcf->filename,
O_WRONLY | O_APPEND | O_CLOEXEC | O_NOCTTY);
}
if (fd >= 0)
break;
flog_err_sys(EC_LIB_SYSTEM_CALL,
"could not open or create log file %pSE: %m",
zcf->filename);
break;
case ZLOG_5424_DST_UNIX:
if (!zcf->filename)
break;
memset(&sa, 0, sizeof(sa));
sa.sun_family = AF_UNIX;
strlcpy(sa.sun_path, zcf->filename, sizeof(sa.sun_path));
/* check if ZLOG_5424_DST_FD needs a touch when changing
* something here. the user can pass in a pre-opened unix
* socket through a fd at startup.
*/
frr_with_privs (lib_privs) {
if (sock_type != -1)
fd = zlog_5424_unix(&sa, sock_type);
else {
for (size_t i = 0; i < array_size(unix_types);
i++) {
fd = zlog_5424_unix(&sa, unix_types[i]);
if (fd != -1) {
zcf->sock_type = unix_types[i];
break;
}
}
}
}
if (fd == -1) {
zcf->sock_type = -1;
flog_err_sys(
EC_LIB_SYSTEM_CALL,
"could not connect to log unix path %pSE: %m",
zcf->filename);
need_reconnect = true;
} else {
/* datagram sockets are connectionless, restarting
* the receiver may lose some packets but will resume
* working afterwards without any action from us.
*/
need_reconnect = (zcf->sock_type != SOCK_DGRAM);
}
break;
}
/* viable on both DST_FD and DST_UNIX path */
if (zcf->sock_type == SOCK_DGRAM) {
zcf->sa_len = sizeof(zcf->sa);
if (getpeername(fd, (struct sockaddr *)&zcf->sa,
&zcf->sa_len)) {
flog_err_sys(
EC_LIB_SYSTEM_CALL,
"could not get remote address for log socket. logging may break if log receiver restarts.");
zcf->sa_len = 0;
}
}
if (do_chown) {
uid_t uid = zcf->file_uid;
gid_t gid = zcf->file_gid;
if (uid != (uid_t)-1 || gid != (gid_t)-1) {
frr_with_privs (lib_privs) {
err = fchown(fd, uid, gid);
}
if (err)
flog_err_sys(
EC_LIB_SYSTEM_CALL,
"failed to chown() log file %pSE: %m",
zcf->filename);
}
}
if (need_reconnect) {
assert(zcf->master);
if (fd != -1) {
thread_add_read(zcf->master, zlog_5424_reconnect, zcf,
fd, &zcf->t_reconnect);
zcf->reconn_backoff_cur = zcf->reconn_backoff;
} else {
thread_add_timer_msec(zcf->master, zlog_5424_reconnect,
zcf, zcf->reconn_backoff_cur,
&zcf->t_reconnect);
zcf->reconn_backoff_cur += zcf->reconn_backoff_cur / 2;
if (zcf->reconn_backoff_cur > zcf->reconn_backoff_max)
zcf->reconn_backoff_cur =
zcf->reconn_backoff_max;
}
}
return fd;
}
bool zlog_5424_apply_dst(struct zlog_cfg_5424 *zcf)
{
int fd = -1;
thread_cancel(&zcf->t_reconnect);
if (zcf->prio_min != ZLOG_DISABLED)
fd = zlog_5424_open(zcf, -1);
frr_with_mutex (&zcf->cfg_mtx) {
zlog_5424_cycle(zcf, fd);
}
return fd != -1;
}
bool zlog_5424_apply_meta(struct zlog_cfg_5424 *zcf)
{
frr_with_mutex (&zcf->cfg_mtx) {
if (zcf->active)
zlog_5424_cycle(zcf, zcf->active->fd);
}
return true;
}
void zlog_5424_state(struct zlog_cfg_5424 *zcf, size_t *lost_msgs,
int *last_errno, bool *stale_errno, struct timeval *err_ts)
{
if (lost_msgs)
*lost_msgs =
zcf->active
? atomic_load_explicit(&zcf->active->lost_msgs,
memory_order_relaxed)
: 0;
if (last_errno)
*last_errno = zcf->active ? zcf->active->last_err : 0;
if (stale_errno)
*stale_errno = zcf->active ? !zcf->active->current_err : 0;
if (err_ts && zcf->active)
*err_ts = zcf->active->last_err_ts;
}
struct rcu_close_rotate {
struct rcu_head_close head_close;
struct rcu_head head_self;
};
bool zlog_5424_rotate(struct zlog_cfg_5424 *zcf)
{
struct rcu_close_rotate *rcr;
int fd;
frr_with_mutex (&zcf->cfg_mtx) {
if (!zcf->active)
return true;
thread_cancel(&zcf->t_reconnect);
/* need to retain the socket type because it also influences
* other fields (packets) and we can't atomically swap these
* out. But we really want the atomic swap so we neither lose
* nor duplicate log messages, particularly for file targets.
*
* (zlog_5424_apply_dst / zlog_target_replace will cause
* duplicate log messages if another thread logs something
* while we're right in the middle of swapping out the log
* target)
*/
fd = zlog_5424_open(zcf, zcf->sock_type);
if (fd < 0)
return false;
fd = atomic_exchange_explicit(&zcf->active->fd,
(uint_fast32_t)fd,
memory_order_relaxed);
}
rcr = XCALLOC(MTYPE_LOG_5424_ROTATE, sizeof(*rcr));
rcu_close(&rcr->head_close, fd);
rcu_free(MTYPE_LOG_5424_ROTATE, rcr, head_self);
return true;
}