On Tue, Oct 17, 2023 at 10:06:54AM +0200, Sebastian Benoit wrote: > Theo Buehler(t...@theobuehler.org) on 2023.10.17 09:13:15 +0200: > > On Mon, Oct 16, 2023 at 12:19:17PM +0200, Claudio Jeker wrote: > > > I dislike how log.c does all these asprintf() calls with dubious > > > workaround calls in case asprintf() fails. > > > > You're not alone. > > > > > IMO it is easier to use the stdio provided buffers and fflush() to get > > > "atomic" writes on stderr. At least from my understanding this is the > > > reason to go all this lenght to do a single fprintf call. > > > > This makes sense, but I don't know the history here. > > as far as i can remember, it was done so it would still be able to work > somewhat when out of memeory. >
After some input off-list here another idea. Require that logit() is called with a \n and by that simplify a lot of code around it. vsyslog() handles both so having the \n should not cause any breakage. Now logit() is mostly used internally but in bgpd it is also used in logmsg.c and parse.y. Fixing those is simple. Also this uses a stack buffer for all the log_* cases now. This should make the code more thread safe. Also this removes vlog() from the API. I had a quick look at all the other log.c users and apart from ldapd this can be added to all of them without much issues. Nothing else uses vlog() and the logit() is also very minimal (mostly the same parse.y change as below). -- :wq Claudio Index: log.c =================================================================== RCS file: /cvs/src/usr.sbin/bgpd/log.c,v retrieving revision 1.64 diff -u -p -r1.64 log.c --- log.c 21 Mar 2017 12:06:55 -0000 1.64 +++ log.c 18 Oct 2023 07:10:32 -0000 @@ -26,6 +26,8 @@ #include "log.h" +#define MAX_LOGLEN 4096 + static int debug; static int verbose; static const char *log_procname; @@ -68,30 +70,15 @@ void logit(int pri, const char *fmt, ...) { va_list ap; + int saved_errno = errno; va_start(ap, fmt); - vlog(pri, fmt, ap); - va_end(ap); -} - -void -vlog(int pri, const char *fmt, va_list ap) -{ - char *nfmt; - int saved_errno = errno; - if (debug) { - /* best effort in out of mem situations */ - if (asprintf(&nfmt, "%s\n", fmt) == -1) { - vfprintf(stderr, fmt, ap); - fprintf(stderr, "\n"); - } else { - vfprintf(stderr, nfmt, ap); - free(nfmt); - } + vfprintf(stderr, fmt, ap); fflush(stderr); } else vsyslog(pri, fmt, ap); + va_end(ap); errno = saved_errno; } @@ -99,26 +86,18 @@ vlog(int pri, const char *fmt, va_list a void log_warn(const char *emsg, ...) { - char *nfmt; - va_list ap; - int saved_errno = errno; + char fmtbuf[MAX_LOGLEN]; + va_list ap; + int saved_errno = errno; /* best effort to even work in out of memory situations */ if (emsg == NULL) - logit(LOG_ERR, "%s", strerror(saved_errno)); + logit(LOG_ERR, "%s\n", strerror(saved_errno)); else { va_start(ap, emsg); - - if (asprintf(&nfmt, "%s: %s", emsg, - strerror(saved_errno)) == -1) { - /* we tried it... */ - vlog(LOG_ERR, emsg, ap); - logit(LOG_ERR, "%s", strerror(saved_errno)); - } else { - vlog(LOG_ERR, nfmt, ap); - free(nfmt); - } + (void)vsnprintf(fmtbuf, sizeof(fmtbuf), emsg, ap); va_end(ap); + logit(LOG_ERR, "%s: %s\n", fmtbuf, strerror(saved_errno)); } errno = saved_errno; @@ -127,53 +106,65 @@ log_warn(const char *emsg, ...) void log_warnx(const char *emsg, ...) { - va_list ap; + char fmtbuf[MAX_LOGLEN]; + va_list ap; + int saved_errno = errno; va_start(ap, emsg); - vlog(LOG_ERR, emsg, ap); + (void)vsnprintf(fmtbuf, sizeof(fmtbuf), emsg, ap); va_end(ap); + logit(LOG_ERR, "%s\n", fmtbuf); + + errno = saved_errno; } void log_info(const char *emsg, ...) { - va_list ap; + char fmtbuf[MAX_LOGLEN]; + va_list ap; + int saved_errno = errno; va_start(ap, emsg); - vlog(LOG_INFO, emsg, ap); + (void)vsnprintf(fmtbuf, sizeof(fmtbuf), emsg, ap); va_end(ap); + logit(LOG_INFO, "%s\n", fmtbuf); + + errno = saved_errno; } void log_debug(const char *emsg, ...) { - va_list ap; + char fmtbuf[MAX_LOGLEN]; + va_list ap; if (verbose) { va_start(ap, emsg); - vlog(LOG_DEBUG, emsg, ap); + (void)vsnprintf(fmtbuf, sizeof(fmtbuf), emsg, ap); va_end(ap); + logit(LOG_DEBUG, "%s\n", fmtbuf); } } static void vfatalc(int code, const char *emsg, va_list ap) { - static char s[BUFSIZ]; + char fmtbuf[MAX_LOGLEN]; const char *sep; if (emsg != NULL) { - (void)vsnprintf(s, sizeof(s), emsg, ap); + (void)vsnprintf(fmtbuf, sizeof(fmtbuf), emsg, ap); sep = ": "; } else { - s[0] = '\0'; + fmtbuf[0] = '\0'; sep = ""; } if (code) - logit(LOG_CRIT, "fatal in %s: %s%s%s", - log_procname, s, sep, strerror(code)); + logit(LOG_CRIT, "fatal in %s: %s%s%s\n", + log_procname, fmtbuf, sep, strerror(code)); else - logit(LOG_CRIT, "fatal in %s%s%s", log_procname, sep, s); + logit(LOG_CRIT, "fatal in %s%s%s\n", log_procname, sep, fmtbuf); } void Index: log.h =================================================================== RCS file: /cvs/src/usr.sbin/bgpd/log.h,v retrieving revision 1.20 diff -u -p -r1.20 log.h --- log.h 21 Oct 2020 06:48:33 -0000 1.20 +++ log.h 18 Oct 2023 07:05:17 -0000 @@ -36,8 +36,6 @@ void log_debug(const char *, ...) __attribute__((__format__ (printf, 1, 2))); void logit(int, const char *, ...) __attribute__((__format__ (printf, 2, 3))); -void vlog(int, const char *, va_list) - __attribute__((__format__ (printf, 2, 0))); __dead void fatal(const char *, ...) __attribute__((__format__ (printf, 1, 2))); __dead void fatalx(const char *, ...) Index: logmsg.c =================================================================== RCS file: /cvs/src/usr.sbin/bgpd/logmsg.c,v retrieving revision 1.10 diff -u -p -r1.10 logmsg.c --- logmsg.c 14 Oct 2023 09:46:14 -0000 1.10 +++ logmsg.c 18 Oct 2023 07:04:57 -0000 @@ -68,7 +68,7 @@ log_peer_info(const struct peer_config * if (vasprintf(&msg, emsg, ap) == -1) fatal(NULL); va_end(ap); - logit(LOG_INFO, "%s: %s", p, msg); + logit(LOG_INFO, "%s: %s\n", p, msg); free(msg); free(p); } @@ -82,13 +82,13 @@ log_peer_warn(const struct peer_config * p = log_fmt_peer(peer); if (emsg == NULL) { - logit(LOG_ERR, "%s: %s", p, strerror(saved_errno)); + logit(LOG_ERR, "%s: %s\n", p, strerror(saved_errno)); } else { va_start(ap, emsg); if (vasprintf(&msg, emsg, ap) == -1) fatal(NULL); va_end(ap); - logit(LOG_ERR, "%s: %s: %s", p, msg, strerror(saved_errno)); + logit(LOG_ERR, "%s: %s: %s\n", p, msg, strerror(saved_errno)); free(msg); } free(p); @@ -105,7 +105,7 @@ log_peer_warnx(const struct peer_config if (vasprintf(&msg, emsg, ap) == -1) fatal(NULL); va_end(ap); - logit(LOG_ERR, "%s: %s", p, msg); + logit(LOG_ERR, "%s: %s\n", p, msg); free(msg); free(p); } @@ -126,7 +126,7 @@ log_statechange(struct peer *peer, enum peer->lasterr = 0; p = log_fmt_peer(&peer->conf); - logit(LOG_INFO, "%s: state change %s -> %s, reason: %s", + logit(LOG_INFO, "%s: state change %s -> %s, reason: %s\n", p, statenames[peer->state], statenames[nstate], eventnames[event]); free(p); } @@ -189,20 +189,20 @@ log_notification(const struct peer *peer break; default: logit(LOG_ERR, "%s: %s notification, unknown errcode " - "%u, subcode %u", p, dir, errcode, subcode); + "%u, subcode %u\n", p, dir, errcode, subcode); free(p); return; } if (uk) - logit(LOG_ERR, "%s: %s notification: %s, unknown subcode %u", + logit(LOG_ERR, "%s: %s notification: %s, unknown subcode %u\n", p, dir, errnames[errcode], subcode); else { if (suberrname == NULL) - logit(LOG_ERR, "%s: %s notification: %s", p, + logit(LOG_ERR, "%s: %s notification: %s\n", p, dir, errnames[errcode]); else - logit(LOG_ERR, "%s: %s notification: %s, %s", + logit(LOG_ERR, "%s: %s notification: %s, %s\n", p, dir, errnames[errcode], suberrname); } free(p); @@ -215,7 +215,7 @@ log_conn_attempt(const struct peer *peer if (peer == NULL) { /* connection from non-peer, drop */ if (log_getverbose()) - logit(LOG_INFO, "connection from non-peer %s refused", + logit(LOG_INFO, "connection from non-peer %s refused\n", log_sockaddr(sa, len)); } else { /* only log if there is a chance that the session may come up */ @@ -223,7 +223,7 @@ log_conn_attempt(const struct peer *peer return; p = log_fmt_peer(&peer->conf); logit(LOG_INFO, "Connection attempt from %s while session is " - "in state %s", p, statenames[peer->state]); + "in state %s\n", p, statenames[peer->state]); free(p); } } Index: parse.y =================================================================== RCS file: /cvs/src/usr.sbin/bgpd/parse.y,v retrieving revision 1.455 diff -u -p -r1.455 parse.y --- parse.y 16 Aug 2023 08:26:35 -0000 1.455 +++ parse.y 18 Oct 2023 07:20:46 -0000 @@ -3477,7 +3477,7 @@ yyerror(const char *fmt, ...) if (vasprintf(&msg, fmt, ap) == -1) fatalx("yyerror vasprintf"); va_end(ap); - logit(LOG_CRIT, "%s:%d: %s", file->name, yylval.lineno, msg); + logit(LOG_CRIT, "%s:%d: %s\n", file->name, yylval.lineno, msg); free(msg); return (0); }