]> git.proxmox.com Git - mirror_frr.git/blob - lib/zlog_5424.c
*: Convert thread_cancelXXX to event_cancelXXX
[mirror_frr.git] / lib / zlog_5424.c
1 // SPDX-License-Identifier: ISC
2 /*
3 * Copyright (c) 2015-21 David Lamparter, for NetDEF, Inc.
4 */
5
6 /* when you work on this code, please install a fuzzer (e.g. AFL) and run
7 * tests/lib/fuzz_zlog.c
8 *
9 * The most likely type of bug in this code is an off-by-one error in the
10 * buffer management pieces, and this isn't easily covered by an unit test
11 * or topotests. Fuzzing is the best tool here, but the CI can't do that
12 * since it's quite resource intensive.
13 */
14
15 #include "zebra.h"
16
17 #include "zlog_5424.h"
18
19 #include <sys/un.h>
20 #include <syslog.h>
21
22 #include "memory.h"
23 #include "frrcu.h"
24 #include "printfrr.h"
25 #include "typerb.h"
26 #include "frr_pthread.h"
27 #include "command.h"
28 #include "monotime.h"
29 #include "event.h"
30
31 #include "lib/version.h"
32 #include "lib/lib_errors.h"
33
34 DEFINE_MTYPE_STATIC(LOG, LOG_5424, "extended log target");
35 DEFINE_MTYPE_STATIC(LOG, LOG_5424_ROTATE, "extended log rotate helper");
36
37 /* the actual log target data structure
38 *
39 * remember this is RCU'd by the core zlog functions. Changing anything
40 * works by allocating a new struct, filling it, adding it, and removing the
41 * old one.
42 */
43 struct zlt_5424 {
44 struct zlog_target zt;
45
46 atomic_uint_fast32_t fd;
47
48 enum zlog_5424_format fmt;
49 uint32_t ts_flags;
50 int facility;
51
52 /* the various extra pieces to add... */
53 bool kw_version : 1;
54 bool kw_location : 1;
55 bool kw_uid : 1;
56 bool kw_ec : 1;
57 bool kw_args : 1;
58
59 /* some formats may or may not include the trailing \n */
60 bool use_nl : 1;
61
62 /* for DGRAM & SEQPACKET sockets, send 1 log message per packet, since
63 * the socket preserves packet boundaries. On Linux, this uses
64 * sendmmsg() for efficiency, on other systems we need a syscall each.
65 */
66 bool packets : 1;
67
68 /* for DGRAM, in order to not have to reconnect, we need to use
69 * sendto()/sendmsg() with the destination given; otherwise we'll get
70 * ENOTCONN. (We do a connect(), which serves to verify the type of
71 * socket, but if the receiver goes away, the kernel disconnects the
72 * socket so writev() no longer works since the destination is now
73 * unspecified.)
74 */
75 struct sockaddr_storage sa;
76 socklen_t sa_len;
77
78 /* these are both getting set, but current_err is cleared on success,
79 * so we know whether the error is current or past.
80 */
81 int last_err, current_err;
82 atomic_size_t lost_msgs;
83 struct timeval last_err_ts;
84
85 struct rcu_head_close head_close;
86 };
87
88 static int zlog_5424_open(struct zlog_cfg_5424 *zcf, int sock_type);
89
90 /* rough header length estimate
91 * ============================
92 *
93 * ^ = might grow
94 *
95 * 49^ longest filename (pceplib/test/pcep_utils_double_linked_list_test.h)
96 * 5^ highest line number (48530, bgpd/bgp_nb_config.c)
97 * 65^ longest function name
98 * (lib_prefix_list_entry_ipv6_prefix_length_greater_or_equal_destroy)
99 * 11 unique id ("XXXXX-XXXXX")
100 * 10 EC ("4294967295" or "0xffffffff")
101 * 35 ISO8601 TS at full length ("YYYY-MM-DD HH:MM:SS.NNNNNNNNN+ZZ:ZZ")
102 * ---
103 * 175
104 *
105 * rarely used (hopefully...):
106 * 26^ FRR_VERSION ("10.10.10-dev-gffffffffffff")
107 * ---
108 * 201
109 *
110 * x16 highest number of format parameters currently
111 * 40 estimate for hostname + 2*daemon + pid
112 *
113 * specific format overhead:
114 *
115 * RFC3164 - shorter than the others
116 * RFC5424 - 175 + "<999>1 "=7 + 52 (location@50145) + 40 (host/...)
117 * rarely: + 65 + 26 (for [origin])
118 * args: 16 * (8 + per-arg (20?)) = ~448
119 *
120 * so without "args@", origin or (future) keywords, around 256 seems OK
121 * with args@ and/or origin and/or keywords, 512 seems more reasonable
122 *
123 * but - note the code allocates this amount multiplied by the number of
124 * messages in the incoming batch (minimum 3), this means short messages and
125 * long messages smooth each other out.
126 *
127 * Since the code handles space-exceeded by grabbing a bunch of stack memory,
128 * a reasonable middle ground estimate is desirable here, so ...
129 * *drumroll*
130 * let's go with 128 + args?128. (remember the minimum 3 multiplier)
131 *
132 * low_space is the point where we don't try to fit another message in & just
133 * submit what we have to the kernel.
134 *
135 * The zlog code only buffers debug & informational messages, so in production
136 * usage most of the calls will be writing out only 1 message. This makes
137 * the min *3 multiplier quite useful.
138 */
139
140 static inline size_t zlog_5424_bufsz(struct zlt_5424 *zte, size_t nmsgs,
141 size_t *low_space)
142 {
143 size_t ret = 128;
144
145 if (zte->kw_args)
146 ret += 128;
147 *low_space = ret;
148 return ret * MAX(nmsgs, 3);
149 }
150
151 struct state {
152 struct fbuf *fbuf;
153 struct iovec *iov;
154 };
155
156 /* stack-based keyword support is likely to bump this to 3 or 4 */
157 #define IOV_PER_MSG 2
158 _Static_assert(IOV_MAX >= IOV_PER_MSG,
159 "this code won't work with IOV_MAX < IOV_PER_MSG");
160
161 /* the following functions are quite similar, but trying to merge them just
162 * makes a big mess. check the others when touching one.
163 *
164 * timestamp keywords hostname
165 * RFC5424 ISO8601 yes yes
166 * RFC3164 RFC3164 no yes
167 * local RFC3164 no no
168 * journald ISO8601(unused) yes (unused)
169 */
170
171 static size_t zlog_5424_one(struct zlt_5424 *zte, struct zlog_msg *msg,
172 struct state *state)
173 {
174 size_t textlen;
175 struct fbuf *fbuf = state->fbuf;
176 char *orig_pos = fbuf->pos;
177 size_t need = 0;
178 int prio = zlog_msg_prio(msg);
179 intmax_t pid, tid;
180
181 zlog_msg_pid(msg, &pid, &tid);
182
183 need += bprintfrr(fbuf, "<%d>1 ", prio | zte->facility);
184 need += zlog_msg_ts(msg, fbuf, zte->ts_flags);
185 need += bprintfrr(fbuf, " %s %s %jd %.*s ", cmd_hostname_get() ?: "-",
186 zlog_progname, pid, (int)(zlog_prefixsz - 2),
187 zlog_prefix);
188
189 if (zte->kw_version)
190 need += bprintfrr(
191 fbuf,
192 "[origin enterpriseId=\"50145\" software=\"FRRouting\" swVersion=\"%s\"]",
193 FRR_VERSION);
194
195 const struct xref_logmsg *xref;
196 struct xrefdata *xrefdata;
197
198 need += bprintfrr(fbuf, "[location@50145 tid=\"%jd\"", tid);
199 if (zlog_instance > 0)
200 need += bprintfrr(fbuf, " instance=\"%d\"", zlog_instance);
201
202 xref = zlog_msg_xref(msg);
203 xrefdata = xref ? xref->xref.xrefdata : NULL;
204 if (xrefdata) {
205 if (zte->kw_uid)
206 need += bprintfrr(fbuf, " id=\"%s\"", xrefdata->uid);
207 if (zte->kw_ec && prio <= LOG_WARNING)
208 need += bprintfrr(fbuf, " ec=\"%u\"", xref->ec);
209 if (zte->kw_location)
210 need += bprintfrr(
211 fbuf, " file=\"%s\" line=\"%d\" func=\"%s\"",
212 xref->xref.file, xref->xref.line,
213 xref->xref.func);
214 }
215 need += bputch(fbuf, ']');
216
217 size_t hdrlen, n_argpos;
218 const struct fmt_outpos *argpos;
219 const char *text;
220
221 text = zlog_msg_text(msg, &textlen);
222 zlog_msg_args(msg, &hdrlen, &n_argpos, &argpos);
223
224 if (zte->kw_args && n_argpos) {
225 need += bputs(fbuf, "[args@50145");
226
227 for (size_t i = 0; i < n_argpos; i++) {
228 int len = argpos[i].off_end - argpos[i].off_start;
229
230 need += bprintfrr(fbuf, " arg%zu=%*pSQsq", i + 1, len,
231 text + argpos[i].off_start);
232 }
233
234 need += bputch(fbuf, ']');
235 }
236
237 need += bputch(fbuf, ' ');
238
239 if (orig_pos + need > fbuf->buf + fbuf->len) {
240 /* not enough space in the buffer for headers. the loop in
241 * zlog_5424() will flush other messages that are already in
242 * the buffer, grab a bigger buffer if needed, and try again.
243 */
244 fbuf->pos = orig_pos;
245 return need;
246 }
247
248 /* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
249 state->iov->iov_base = orig_pos;
250 state->iov->iov_len = fbuf->pos - orig_pos;
251 state->iov++;
252
253 state->iov->iov_base = (char *)text + hdrlen;
254 state->iov->iov_len = textlen - hdrlen + zte->use_nl;
255 state->iov++;
256 return 0;
257 }
258
259 static size_t zlog_3164_one(struct zlt_5424 *zte, struct zlog_msg *msg,
260 struct state *state)
261 {
262 size_t textlen;
263 struct fbuf *fbuf = state->fbuf;
264 char *orig_pos = fbuf->pos;
265 size_t need = 0;
266 int prio = zlog_msg_prio(msg);
267 intmax_t pid, tid;
268
269 zlog_msg_pid(msg, &pid, &tid);
270
271 need += bprintfrr(fbuf, "<%d>", prio | zte->facility);
272 need += zlog_msg_ts_3164(msg, fbuf, zte->ts_flags);
273 if (zte->fmt != ZLOG_FMT_LOCAL) {
274 need += bputch(fbuf, ' ');
275 need += bputs(fbuf, cmd_hostname_get() ?: "-");
276 }
277 need += bprintfrr(fbuf, " %s[%jd]: ", zlog_progname, pid);
278
279 if (orig_pos + need > fbuf->buf + fbuf->len) {
280 /* not enough space in the buffer for headers. loop in
281 * zlog_5424() will flush other messages that are already in
282 * the buffer, grab a bigger buffer if needed, and try again.
283 */
284 fbuf->pos = orig_pos;
285 return need;
286 }
287
288 /* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
289 state->iov->iov_base = orig_pos;
290 state->iov->iov_len = fbuf->pos - orig_pos;
291 state->iov++;
292
293 state->iov->iov_base = (char *)zlog_msg_text(msg, &textlen);
294 state->iov->iov_len = textlen + zte->use_nl;
295 state->iov++;
296 return 0;
297 }
298
299 static size_t zlog_journald_one(struct zlt_5424 *zte, struct zlog_msg *msg,
300 struct state *state)
301 {
302 size_t textlen;
303 struct fbuf *fbuf = state->fbuf;
304 char *orig_pos = fbuf->pos;
305 size_t need = 0;
306 int prio = zlog_msg_prio(msg);
307 intmax_t pid, tid;
308
309 zlog_msg_pid(msg, &pid, &tid);
310
311 need += bprintfrr(fbuf,
312 "PRIORITY=%d\n"
313 "SYSLOG_FACILITY=%d\n"
314 "TID=%jd\n"
315 "FRR_DAEMON=%s\n"
316 "SYSLOG_TIMESTAMP=",
317 prio, zte->facility, tid, zlog_progname);
318 need += zlog_msg_ts(msg, fbuf, zte->ts_flags);
319 need += bputch(fbuf, '\n');
320 if (zlog_instance > 0)
321 need += bprintfrr(fbuf, "FRR_INSTANCE=%d\n", zlog_instance);
322
323 const struct xref_logmsg *xref;
324 struct xrefdata *xrefdata;
325
326 xref = zlog_msg_xref(msg);
327 xrefdata = xref ? xref->xref.xrefdata : NULL;
328 if (xrefdata) {
329 if (zte->kw_uid && xrefdata->uid[0])
330 need += bprintfrr(fbuf, "FRR_ID=%s\n", xrefdata->uid);
331 if (zte->kw_ec && prio <= LOG_WARNING)
332 need += bprintfrr(fbuf, "FRR_EC=%d\n", xref->ec);
333 if (zte->kw_location)
334 need += bprintfrr(fbuf,
335 "CODE_FILE=%s\n"
336 "CODE_LINE=%d\n"
337 "CODE_FUNC=%s\n",
338 xref->xref.file, xref->xref.line,
339 xref->xref.func);
340 }
341
342 size_t hdrlen, n_argpos;
343 const struct fmt_outpos *argpos;
344 const char *text;
345
346 text = zlog_msg_text(msg, &textlen);
347 zlog_msg_args(msg, &hdrlen, &n_argpos, &argpos);
348
349 if (zte->kw_args && n_argpos) {
350 for (size_t i = 0; i < n_argpos; i++) {
351 int len = argpos[i].off_end - argpos[i].off_start;
352
353 /* rather than escape the value, we could use
354 * journald's binary encoding, but that seems a bit
355 * excessive/unnecessary. 99% of things we print here
356 * will just output 1:1 with %pSE.
357 */
358 need += bprintfrr(fbuf, "FRR_ARG%zu=%*pSE\n", i + 1,
359 len, text + argpos[i].off_start);
360 }
361 }
362
363 need += bputs(fbuf, "MESSAGE=");
364
365 if (orig_pos + need > fbuf->buf + fbuf->len) {
366 /* not enough space in the buffer for headers. loop in
367 * zlog_5424() will flush other messages that are already in
368 * the buffer, grab a bigger buffer if needed, and try again.
369 */
370 fbuf->pos = orig_pos;
371 return need;
372 }
373
374 /* NB: zlog_5424 below assumes we use max. IOV_PER_MSG iovs here */
375 state->iov->iov_base = orig_pos;
376 state->iov->iov_len = fbuf->pos - orig_pos;
377 state->iov++;
378
379 state->iov->iov_base = (char *)text + hdrlen;
380 state->iov->iov_len = textlen - hdrlen + 1;
381 state->iov++;
382 return 0;
383 }
384
385 static size_t zlog_one(struct zlt_5424 *zte, struct zlog_msg *msg,
386 struct state *state)
387 {
388 switch (zte->fmt) {
389 case ZLOG_FMT_5424:
390 return zlog_5424_one(zte, msg, state);
391 case ZLOG_FMT_3164:
392 case ZLOG_FMT_LOCAL:
393 return zlog_3164_one(zte, msg, state);
394 case ZLOG_FMT_JOURNALD:
395 return zlog_journald_one(zte, msg, state);
396 }
397 return 0;
398 }
399
400 static void zlog_5424_err(struct zlt_5424 *zte, size_t count)
401 {
402 if (!count) {
403 zte->current_err = 0;
404 return;
405 }
406
407 /* only the counter is atomic because otherwise it'd be meaningless */
408 atomic_fetch_add_explicit(&zte->lost_msgs, count, memory_order_relaxed);
409
410 /* these are non-atomic and can provide wrong results when read, but
411 * since they're only for debugging / display, that's OK.
412 */
413 zte->current_err = zte->last_err = errno;
414 monotime(&zte->last_err_ts);
415 }
416
417 static void zlog_5424(struct zlog_target *zt, struct zlog_msg *msgs[],
418 size_t nmsgs)
419 {
420 size_t i;
421 struct zlt_5424 *zte = container_of(zt, struct zlt_5424, zt);
422 int fd, ret;
423 size_t niov = MIN(IOV_PER_MSG * nmsgs, IOV_MAX);
424 struct iovec iov[niov], *iov_last = iov + niov;
425 struct mmsghdr mmsg[zte->packets ? nmsgs : 1], *mpos = mmsg;
426 size_t count = 0;
427
428 /* refer to size estimate at top of file */
429 size_t low_space;
430 char hdr_buf[zlog_5424_bufsz(zte, nmsgs, &low_space)];
431 struct fbuf hdr_pos = {
432 .buf = hdr_buf,
433 .pos = hdr_buf,
434 .len = sizeof(hdr_buf),
435 };
436 struct state state = {
437 .fbuf = &hdr_pos,
438 .iov = iov,
439 };
440
441 fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
442
443 memset(mmsg, 0, sizeof(mmsg));
444 if (zte->sa_len) {
445 for (i = 0; i < array_size(mmsg); i++) {
446 mmsg[i].msg_hdr.msg_name = (struct sockaddr *)&zte->sa;
447 mmsg[i].msg_hdr.msg_namelen = zte->sa_len;
448 }
449 }
450 mmsg[0].msg_hdr.msg_iov = iov;
451
452 for (i = 0; i < nmsgs; i++) {
453 int prio = zlog_msg_prio(msgs[i]);
454 size_t need = 0;
455
456 if (prio <= zte->zt.prio_min) {
457 if (zte->packets)
458 mpos->msg_hdr.msg_iov = state.iov;
459
460 need = zlog_one(zte, msgs[i], &state);
461
462 if (zte->packets) {
463 mpos->msg_hdr.msg_iovlen =
464 state.iov - mpos->msg_hdr.msg_iov;
465 mpos++;
466 }
467 count++;
468 }
469
470 /* clang-format off */
471 if ((need
472 || (size_t)(hdr_pos.buf + hdr_pos.len - hdr_pos.pos)
473 < low_space
474 || i + 1 == nmsgs
475 || state.iov + IOV_PER_MSG > iov_last)
476 && state.iov > iov) {
477 /* clang-format on */
478
479 if (zte->packets) {
480 struct mmsghdr *sendpos;
481
482 for (sendpos = mmsg; sendpos < mpos;) {
483 ret = sendmmsg(fd, sendpos,
484 mpos - sendpos, 0);
485 if (ret <= 0)
486 break;
487 sendpos += ret;
488 }
489 zlog_5424_err(zte, mpos - sendpos);
490 mpos = mmsg;
491 } else {
492 if (!zte->sa_len)
493 ret = writev(fd, iov, state.iov - iov);
494 else {
495 mpos->msg_hdr.msg_iovlen =
496 state.iov - iov;
497 ret = sendmsg(fd, &mpos->msg_hdr, 0);
498 }
499
500 if (ret < 0)
501 zlog_5424_err(zte, count);
502 else
503 zlog_5424_err(zte, 0);
504 }
505
506 count = 0;
507 hdr_pos.pos = hdr_buf;
508 state.iov = iov;
509 }
510
511 /* if need == 0, we just put a message (or nothing) in the
512 * buffer and are continuing for more to batch in a single
513 * writev()
514 */
515 if (need == 0)
516 continue;
517
518 if (need && need <= sizeof(hdr_buf)) {
519 /* don't need to allocate, just try this msg
520 * again without other msgs already using up
521 * buffer space
522 */
523 i--;
524 continue;
525 }
526
527 /* need > sizeof(hdr_buf), need to grab some memory. Taking
528 * it off the stack is fine here.
529 */
530 char buf2[need];
531 struct fbuf fbuf2 = {
532 .buf = buf2,
533 .pos = buf2,
534 .len = sizeof(buf2),
535 };
536
537 state.fbuf = &fbuf2;
538 need = zlog_one(zte, msgs[i], &state);
539 assert(need == 0);
540
541 if (!zte->sa_len)
542 ret = writev(fd, iov, state.iov - iov);
543 else {
544 mpos->msg_hdr.msg_iovlen = state.iov - iov;
545 ret = sendmsg(fd, &mpos->msg_hdr, 0);
546 }
547
548 if (ret < 0)
549 zlog_5424_err(zte, 1);
550 else
551 zlog_5424_err(zte, 0);
552
553 count = 0;
554 state.fbuf = &hdr_pos;
555 state.iov = iov;
556 mpos = mmsg;
557 }
558
559 assert(state.iov == iov);
560 }
561
562 /* strftime(), gmtime_r() and localtime_r() aren't AS-Safe (they access locale
563 * data), but we need an AS-Safe timestamp below :(
564 */
565 static void gmtime_assafe(time_t ts, struct tm *res)
566 {
567 res->tm_sec = ts % 60;
568 ts /= 60;
569 res->tm_min = ts % 60;
570 ts /= 60;
571 res->tm_hour = ts % 24;
572 ts /= 24;
573
574 ts -= 11017; /* start on 2020-03-01, 11017 days since 1970-01-01 */
575
576 /* 1461 days = 3 regular years + 1 leap year
577 * this works until 2100, which isn't a leap year
578 *
579 * struct tm.tm_year starts at 1900.
580 */
581 res->tm_year = 2000 - 1900 + 4 * (ts / 1461);
582 ts = ts % 1461;
583
584 if (ts == 1460) {
585 res->tm_year += 4;
586 res->tm_mon = 1;
587 res->tm_mday = 29;
588 return;
589 }
590 res->tm_year += ts / 365;
591 ts %= 365;
592
593 /* note we're starting in march like the romans did... */
594 if (ts >= 306) /* Jan 1 of next year */
595 res->tm_year++;
596
597 static time_t months[13] = {
598 0, 31, 61, 92, 122, 153, 184, 214, 245, 275, 306, 337, 365,
599 };
600 const size_t month_max = array_size(months) - 1;
601
602 for (size_t i = 0; i < month_max; i++) {
603 if (ts < months[i + 1]) {
604 res->tm_mon = ((i + 2) % 12);
605 res->tm_mday = 1 + ts - months[i];
606 break;
607 }
608 }
609 }
610
611 /* one of the greatest advantages of this logging target: unlike syslog(),
612 * which is not AS-Safe, we can send crashlogs to syslog here.
613 */
614 static void zlog_5424_sigsafe(struct zlog_target *zt, const char *text,
615 size_t len)
616 {
617 static const char *const months_3164[12] = {
618 "Jan", "Feb", "Mar", "Apr", "May", "Jun",
619 "Jul", "Aug", "Sep", "Oct", "Nov", "Dec",
620 };
621
622 struct zlt_5424 *zte = container_of(zt, struct zlt_5424, zt);
623 struct iovec iov[3], *iovp = iov;
624 char buf[256];
625 struct fbuf fbuf = {
626 .buf = buf,
627 .pos = buf,
628 .len = sizeof(buf),
629 };
630 int fd;
631 intmax_t pid = (intmax_t)getpid();
632 struct tm tm;
633
634 switch (zte->fmt) {
635 case ZLOG_FMT_5424:
636 gmtime_assafe(time(NULL), &tm);
637 bprintfrr(
638 &fbuf,
639 "<%d>1 %04u-%02u-%02uT%02u:%02u:%02uZ - %s %jd %.*s ",
640 zte->facility | LOG_CRIT, tm.tm_year + 1900,
641 tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min,
642 tm.tm_sec, zlog_progname, pid, (int)(zlog_prefixsz - 2),
643 zlog_prefix);
644 break;
645
646 case ZLOG_FMT_3164:
647 case ZLOG_FMT_LOCAL:
648 /* this will unfortuantely be wrong by the timezone offset
649 * if the user selected non-UTC. But not much we can do
650 * about that...
651 */
652 gmtime_assafe(time(NULL), &tm);
653 bprintfrr(&fbuf, "<%d>%3s %2u %02u:%02u:%02u %s%s[%jd]: ",
654 zte->facility | LOG_CRIT, months_3164[tm.tm_mon],
655 tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec,
656 (zte->fmt == ZLOG_FMT_LOCAL) ? "" : "- ",
657 zlog_progname, pid);
658 break;
659
660 case ZLOG_FMT_JOURNALD:
661 bprintfrr(&fbuf,
662 "PRIORITY=%d\n"
663 "SYSLOG_FACILITY=%d\n"
664 "FRR_DAEMON=%s\n"
665 "MESSAGE=",
666 LOG_CRIT, zte->facility, zlog_progname);
667 break;
668 }
669
670 iovp->iov_base = fbuf.buf;
671 iovp->iov_len = fbuf.pos - fbuf.buf;
672 iovp++;
673
674 iovp->iov_base = (char *)text;
675 iovp->iov_len = len;
676 iovp++;
677
678 if (zte->use_nl) {
679 iovp->iov_base = (char *)"\n";
680 iovp->iov_len = 1;
681 iovp++;
682 }
683
684 fd = atomic_load_explicit(&zte->fd, memory_order_relaxed);
685
686 if (!zte->sa_len)
687 writev(fd, iov, iovp - iov);
688 else {
689 struct msghdr mh = {};
690
691 mh.msg_name = (struct sockaddr *)&zte->sa;
692 mh.msg_namelen = zte->sa_len;
693 mh.msg_iov = iov;
694 mh.msg_iovlen = iovp - iov;
695 sendmsg(fd, &mh, 0);
696 }
697 }
698
699 /* housekeeping & configuration */
700
701 void zlog_5424_init(struct zlog_cfg_5424 *zcf)
702 {
703 pthread_mutex_init(&zcf->cfg_mtx, NULL);
704 }
705
706 static void zlog_5424_target_free(struct zlt_5424 *zlt)
707 {
708 if (!zlt)
709 return;
710
711 rcu_close(&zlt->head_close, zlt->fd);
712 rcu_free(MTYPE_LOG_5424, zlt, zt.rcu_head);
713 }
714
715 void zlog_5424_fini(struct zlog_cfg_5424 *zcf, bool keepopen)
716 {
717 if (keepopen)
718 zcf->active = NULL;
719
720 if (zcf->active) {
721 struct zlt_5424 *ztf;
722 struct zlog_target *zt;
723
724 zt = zlog_target_replace(&zcf->active->zt, NULL);
725 ztf = container_of(zt, struct zlt_5424, zt);
726 zlog_5424_target_free(ztf);
727 }
728 pthread_mutex_destroy(&zcf->cfg_mtx);
729 }
730
731 static void zlog_5424_cycle(struct zlog_cfg_5424 *zcf, int fd)
732 {
733 struct zlog_target *old;
734 struct zlt_5424 *zlt = NULL, *oldt;
735
736 if (fd >= 0) {
737 struct zlog_target *zt;
738
739 /* all of this is swapped in by zlog_target_replace() below,
740 * the old target is RCU-freed afterwards.
741 */
742 zt = zlog_target_clone(MTYPE_LOG_5424, &zcf->active->zt,
743 sizeof(*zlt));
744 zlt = container_of(zt, struct zlt_5424, zt);
745
746 zlt->fd = fd;
747 zlt->kw_version = zcf->kw_version;
748 zlt->kw_location = zcf->kw_location;
749 zlt->kw_uid = zcf->kw_uid;
750 zlt->kw_ec = zcf->kw_ec;
751 zlt->kw_args = zcf->kw_args;
752 zlt->use_nl = true;
753 zlt->facility = zcf->facility;
754
755 /* DGRAM & SEQPACKET = 1 log message per packet */
756 zlt->packets = (zcf->sock_type == SOCK_DGRAM) ||
757 (zcf->sock_type == SOCK_SEQPACKET);
758 zlt->sa = zcf->sa;
759 zlt->sa_len = zcf->sa_len;
760 zlt->fmt = zcf->fmt;
761 zlt->zt.prio_min = zcf->prio_min;
762 zlt->zt.logfn = zlog_5424;
763 zlt->zt.logfn_sigsafe = zlog_5424_sigsafe;
764
765 switch (zcf->fmt) {
766 case ZLOG_FMT_5424:
767 case ZLOG_FMT_JOURNALD:
768 zlt->ts_flags = zcf->ts_flags;
769 zlt->ts_flags &= ZLOG_TS_PREC | ZLOG_TS_UTC;
770 zlt->ts_flags |= ZLOG_TS_ISO8601;
771 break;
772 case ZLOG_FMT_3164:
773 case ZLOG_FMT_LOCAL:
774 zlt->ts_flags = zcf->ts_flags & ZLOG_TS_UTC;
775 if (zlt->packets)
776 zlt->use_nl = false;
777 break;
778 }
779 }
780
781 old = zcf->active ? &zcf->active->zt : NULL;
782 old = zlog_target_replace(old, &zlt->zt);
783 zcf->active = zlt;
784
785 /* oldt->fd == fd happens for zlog_5424_apply_meta() */
786 oldt = container_of(old, struct zlt_5424, zt);
787 if (oldt && oldt->fd != (unsigned int)fd)
788 rcu_close(&oldt->head_close, oldt->fd);
789 rcu_free(MTYPE_LOG_5424, oldt, zt.rcu_head);
790 }
791
792 static void zlog_5424_reconnect(struct event *t)
793 {
794 struct zlog_cfg_5424 *zcf = THREAD_ARG(t);
795 int fd = THREAD_FD(t);
796 char dummy[256];
797 ssize_t ret;
798
799 if (zcf->active) {
800 ret = read(fd, dummy, sizeof(dummy));
801 if (ret > 0) {
802 /* logger is sending us something?!?! */
803 event_add_read(t->master, zlog_5424_reconnect, zcf, fd,
804 &zcf->t_reconnect);
805 return;
806 }
807
808 if (ret == 0)
809 zlog_warn("logging socket %pSE closed by peer",
810 zcf->filename);
811 else
812 zlog_warn("logging socket %pSE error: %m",
813 zcf->filename);
814 }
815
816 /* do NOT close() anything here; other threads may still be writing
817 * and their messages need to be lost rather than end up on a random
818 * other fd that got reassigned the same number, like a BGP session!
819 */
820 fd = zlog_5424_open(zcf, -1);
821
822 frr_with_mutex (&zcf->cfg_mtx) {
823 zlog_5424_cycle(zcf, fd);
824 }
825 }
826
827 static int zlog_5424_unix(struct sockaddr_un *suna, int sock_type)
828 {
829 int fd;
830 int size = 1 * 1024 * 1024, prev_size;
831 socklen_t opt_size;
832 int save_errno;
833
834 fd = socket(AF_UNIX, sock_type, 0);
835 if (fd < 0)
836 return -1;
837
838 if (connect(fd, (struct sockaddr *)suna, sizeof(*suna))) {
839 /* zlog_5424_open() will print the error for connect() */
840 save_errno = errno;
841 close(fd);
842 errno = save_errno;
843 return -1;
844 }
845
846 opt_size = sizeof(prev_size);
847 if (getsockopt(fd, SOL_SOCKET, SO_SNDBUF, &prev_size, &opt_size))
848 return fd;
849
850 /* setsockopt_so_sendbuf() logs on error; we don't really care that
851 * much here. Also, never shrink the buffer below the initial size.
852 */
853 while (size > prev_size &&
854 setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &size, sizeof(size)) == -1)
855 size /= 2;
856
857 return fd;
858 }
859
860 static int zlog_5424_open(struct zlog_cfg_5424 *zcf, int sock_type)
861 {
862 int fd = -1;
863 int flags = 0;
864 int err;
865 socklen_t optlen;
866 bool do_chown = false;
867 bool need_reconnect = false;
868 static const int unix_types[] = {
869 SOCK_STREAM,
870 SOCK_SEQPACKET,
871 SOCK_DGRAM,
872 };
873 struct sockaddr_un sa;
874
875 zcf->sock_type = -1;
876 zcf->sa_len = 0;
877
878 switch (zcf->dst) {
879 case ZLOG_5424_DST_NONE:
880 break;
881
882 case ZLOG_5424_DST_FD:
883 fd = dup(zcf->fd);
884
885 optlen = sizeof(sock_type);
886 if (!getsockopt(fd, SOL_SOCKET, SO_TYPE, &sock_type, &optlen)) {
887 zcf->sock_type = sock_type;
888 need_reconnect = (zcf->sock_type != SOCK_DGRAM);
889 }
890 break;
891
892 case ZLOG_5424_DST_FIFO:
893 if (!zcf->filename)
894 break;
895
896 if (!zcf->file_nocreate) {
897 frr_with_privs (lib_privs) {
898 mode_t prevmask;
899
900 prevmask = umask(0777 ^ zcf->file_mode);
901 err = mkfifo(zcf->filename, 0666);
902 umask(prevmask);
903 }
904 if (err == 0)
905 do_chown = true;
906 else if (errno != EEXIST)
907 break;
908 }
909
910 flags = O_NONBLOCK;
911 /* fallthru */
912
913 case ZLOG_5424_DST_FILE:
914 if (!zcf->filename)
915 break;
916
917 frr_with_privs (lib_privs) {
918 fd = open(zcf->filename, flags | O_WRONLY | O_APPEND |
919 O_CLOEXEC | O_NOCTTY);
920 }
921 if (fd >= 0)
922 break;
923 if (zcf->file_nocreate || flags) {
924 flog_err_sys(EC_LIB_SYSTEM_CALL,
925 "could not open log file %pSE: %m",
926 zcf->filename);
927 break;
928 }
929
930 frr_with_privs (lib_privs) {
931 mode_t prevmask;
932
933 prevmask = umask(0777 ^ zcf->file_mode);
934 fd = open(zcf->filename,
935 O_WRONLY | O_APPEND | O_CLOEXEC | O_NOCTTY |
936 O_CREAT | O_EXCL,
937 zcf->file_mode);
938 umask(prevmask);
939 }
940 if (fd >= 0) {
941 do_chown = true;
942 break;
943 }
944
945 frr_with_privs (lib_privs) {
946 fd = open(zcf->filename,
947 O_WRONLY | O_APPEND | O_CLOEXEC | O_NOCTTY);
948 }
949 if (fd >= 0)
950 break;
951
952 flog_err_sys(EC_LIB_SYSTEM_CALL,
953 "could not open or create log file %pSE: %m",
954 zcf->filename);
955 break;
956
957 case ZLOG_5424_DST_UNIX:
958 if (!zcf->filename)
959 break;
960
961 memset(&sa, 0, sizeof(sa));
962 sa.sun_family = AF_UNIX;
963 strlcpy(sa.sun_path, zcf->filename, sizeof(sa.sun_path));
964
965 /* check if ZLOG_5424_DST_FD needs a touch when changing
966 * something here. the user can pass in a pre-opened unix
967 * socket through a fd at startup.
968 */
969 frr_with_privs (lib_privs) {
970 if (sock_type != -1)
971 fd = zlog_5424_unix(&sa, sock_type);
972 else {
973 for (size_t i = 0; i < array_size(unix_types);
974 i++) {
975 fd = zlog_5424_unix(&sa, unix_types[i]);
976 if (fd != -1) {
977 zcf->sock_type = unix_types[i];
978 break;
979 }
980 }
981 }
982 }
983 if (fd == -1) {
984 zcf->sock_type = -1;
985
986 flog_err_sys(
987 EC_LIB_SYSTEM_CALL,
988 "could not connect to log unix path %pSE: %m",
989 zcf->filename);
990 need_reconnect = true;
991 } else {
992 /* datagram sockets are connectionless, restarting
993 * the receiver may lose some packets but will resume
994 * working afterwards without any action from us.
995 */
996 need_reconnect = (zcf->sock_type != SOCK_DGRAM);
997 }
998 break;
999 }
1000
1001 /* viable on both DST_FD and DST_UNIX path */
1002 if (zcf->sock_type == SOCK_DGRAM) {
1003 zcf->sa_len = sizeof(zcf->sa);
1004 if (getpeername(fd, (struct sockaddr *)&zcf->sa,
1005 &zcf->sa_len)) {
1006 flog_err_sys(
1007 EC_LIB_SYSTEM_CALL,
1008 "could not get remote address for log socket. logging may break if log receiver restarts.");
1009 zcf->sa_len = 0;
1010 }
1011 }
1012
1013 if (do_chown) {
1014 uid_t uid = zcf->file_uid;
1015 gid_t gid = zcf->file_gid;
1016
1017 if (uid != (uid_t)-1 || gid != (gid_t)-1) {
1018 frr_with_privs (lib_privs) {
1019 err = fchown(fd, uid, gid);
1020 }
1021 if (err)
1022 flog_err_sys(
1023 EC_LIB_SYSTEM_CALL,
1024 "failed to chown() log file %pSE: %m",
1025 zcf->filename);
1026 }
1027 }
1028
1029 if (need_reconnect) {
1030 assert(zcf->master);
1031
1032 if (fd != -1) {
1033 event_add_read(zcf->master, zlog_5424_reconnect, zcf,
1034 fd, &zcf->t_reconnect);
1035 zcf->reconn_backoff_cur = zcf->reconn_backoff;
1036
1037 } else {
1038 event_add_timer_msec(zcf->master, zlog_5424_reconnect,
1039 zcf, zcf->reconn_backoff_cur,
1040 &zcf->t_reconnect);
1041
1042 zcf->reconn_backoff_cur += zcf->reconn_backoff_cur / 2;
1043 if (zcf->reconn_backoff_cur > zcf->reconn_backoff_max)
1044 zcf->reconn_backoff_cur =
1045 zcf->reconn_backoff_max;
1046 }
1047 }
1048
1049 return fd;
1050 }
1051
1052 bool zlog_5424_apply_dst(struct zlog_cfg_5424 *zcf)
1053 {
1054 int fd = -1;
1055
1056 event_cancel(&zcf->t_reconnect);
1057
1058 if (zcf->prio_min != ZLOG_DISABLED)
1059 fd = zlog_5424_open(zcf, -1);
1060
1061 frr_with_mutex (&zcf->cfg_mtx) {
1062 zlog_5424_cycle(zcf, fd);
1063 }
1064 return fd != -1;
1065 }
1066
1067
1068 bool zlog_5424_apply_meta(struct zlog_cfg_5424 *zcf)
1069 {
1070 frr_with_mutex (&zcf->cfg_mtx) {
1071 if (zcf->active)
1072 zlog_5424_cycle(zcf, zcf->active->fd);
1073 }
1074
1075 return true;
1076 }
1077
1078 void zlog_5424_state(struct zlog_cfg_5424 *zcf, size_t *lost_msgs,
1079 int *last_errno, bool *stale_errno, struct timeval *err_ts)
1080 {
1081 if (lost_msgs)
1082 *lost_msgs =
1083 zcf->active
1084 ? atomic_load_explicit(&zcf->active->lost_msgs,
1085 memory_order_relaxed)
1086 : 0;
1087 if (last_errno)
1088 *last_errno = zcf->active ? zcf->active->last_err : 0;
1089 if (stale_errno)
1090 *stale_errno = zcf->active ? !zcf->active->current_err : 0;
1091 if (err_ts && zcf->active)
1092 *err_ts = zcf->active->last_err_ts;
1093 }
1094
1095 struct rcu_close_rotate {
1096 struct rcu_head_close head_close;
1097 struct rcu_head head_self;
1098 };
1099
1100 bool zlog_5424_rotate(struct zlog_cfg_5424 *zcf)
1101 {
1102 struct rcu_close_rotate *rcr;
1103 int fd;
1104
1105 frr_with_mutex (&zcf->cfg_mtx) {
1106 if (!zcf->active)
1107 return true;
1108
1109 event_cancel(&zcf->t_reconnect);
1110
1111 /* need to retain the socket type because it also influences
1112 * other fields (packets) and we can't atomically swap these
1113 * out. But we really want the atomic swap so we neither lose
1114 * nor duplicate log messages, particularly for file targets.
1115 *
1116 * (zlog_5424_apply_dst / zlog_target_replace will cause
1117 * duplicate log messages if another thread logs something
1118 * while we're right in the middle of swapping out the log
1119 * target)
1120 */
1121 fd = zlog_5424_open(zcf, zcf->sock_type);
1122 if (fd < 0)
1123 return false;
1124
1125 fd = atomic_exchange_explicit(&zcf->active->fd,
1126 (uint_fast32_t)fd,
1127 memory_order_relaxed);
1128 }
1129
1130 rcr = XCALLOC(MTYPE_LOG_5424_ROTATE, sizeof(*rcr));
1131 rcu_close(&rcr->head_close, fd);
1132 rcu_free(MTYPE_LOG_5424_ROTATE, rcr, head_self);
1133
1134 return true;
1135 }