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);
}
