On Wed, Oct 18, 2023 at 11:34:09AM +0200, Claudio Jeker wrote: > 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.
Really hard to say which is the lesser evil: requiring \n or the ugly asprintf dances. I don't think it is flat out objectionable, but I can see people disliking this. The churn you outline below seems indeed rather limited, so I guess we can go this way. Definitely ok with using a stack buffer rather than a static one. > > 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); > }