From c1f8818c70b0a2dda195c4121f78004f13ef6c05 Mon Sep 17 00:00:00 2001 From: bluhm Date: Thu, 12 Oct 2023 22:36:54 +0000 Subject: [PATCH] Retry DNS lookup for remote loghost. If DNS lookup for a remote loghost configured in syslog.conf did not work at startup, the entry was ignored. Better retry the lookup in intervals until it succeeds. Improve debug output to print IP address after resolution. Unify retry code that resolves DNS for UDP and connects to TCP server. testing and feedback from Paul de Weerd; OK deraadt@ --- usr.sbin/syslogd/privsep.c | 6 +- usr.sbin/syslogd/syslogd.c | 206 ++++++++++++++++++++++++++++--------- usr.sbin/syslogd/syslogd.h | 5 +- 3 files changed, 163 insertions(+), 54 deletions(-) diff --git a/usr.sbin/syslogd/privsep.c b/usr.sbin/syslogd/privsep.c index 2edbbbca971..3e89894ab46 100644 --- a/usr.sbin/syslogd/privsep.c +++ b/usr.sbin/syslogd/privsep.c @@ -1,4 +1,4 @@ -/* $OpenBSD: privsep.c,v 1.76 2023/08/11 04:45:06 guenther Exp $ */ +/* $OpenBSD: privsep.c,v 1.77 2023/10/12 22:36:54 bluhm Exp $ */ /* * Copyright (c) 2003 Anil Madhavapeddy @@ -742,8 +742,8 @@ priv_config_parse_done(void) /* Name/service to address translation. Response is placed into addr. * Return 0 for success or < 0 for error like getaddrinfo(3) */ int -priv_getaddrinfo(char *proto, char *host, char *serv, struct sockaddr *addr, - size_t addr_len) +priv_getaddrinfo(const char *proto, const char *host, const char *serv, + struct sockaddr *addr, size_t addr_len) { char protocpy[5], hostcpy[NI_MAXHOST], servcpy[NI_MAXSERV]; int cmd, ret_len; diff --git a/usr.sbin/syslogd/syslogd.c b/usr.sbin/syslogd/syslogd.c index 289c3cb68a9..e878a30d5ee 100644 --- a/usr.sbin/syslogd/syslogd.c +++ b/usr.sbin/syslogd/syslogd.c @@ -1,4 +1,4 @@ -/* $OpenBSD: syslogd.c,v 1.277 2023/03/16 18:22:08 bluhm Exp $ */ +/* $OpenBSD: syslogd.c,v 1.278 2023/10/12 22:36:54 bluhm Exp $ */ /* * Copyright (c) 2014-2021 Alexander Bluhm @@ -156,9 +156,12 @@ struct filed { struct sockaddr_storage f_addr; struct buffertls f_buftls; struct bufferevent *f_bufev; + struct event f_ev; struct tls *f_ctx; + char *f_ipproto; char *f_host; - int f_reconnectwait; + char *f_port; + int f_retrywait; } f_forw; /* forwarding address */ char f_fname[PATH_MAX]; struct { @@ -319,7 +322,9 @@ void tcp_dropcb(struct bufferevent *, void *); void tcp_writecb(struct bufferevent *, void *); void tcp_errorcb(struct bufferevent *, short, void *); void tcp_connectcb(int, short, void *); -void tcp_connect_retry(struct bufferevent *, struct filed *); +int loghost_resolve(struct filed *); +void loghost_retry(struct filed *); +void udp_resolvecb(int, short, void *); int tcpbuf_countmsg(struct bufferevent *bufev); void die_signalcb(int, short, void *); void mark_timercb(int, short, void *); @@ -962,12 +967,15 @@ socket_bind(const char *proto, const char *host, const char *port, res->ai_socktype | SOCK_NONBLOCK, res->ai_protocol)) == -1) continue; - if (getnameinfo(res->ai_addr, res->ai_addrlen, hostname, + error = getnameinfo(res->ai_addr, res->ai_addrlen, hostname, sizeof(hostname), servname, sizeof(servname), NI_NUMERICHOST | NI_NUMERICSERV | - (res->ai_socktype == SOCK_DGRAM ? NI_DGRAM : 0)) != 0) { - log_debug("Malformed bind address"); - hostname[0] = servname[0] = '\0'; + (res->ai_socktype == SOCK_DGRAM ? NI_DGRAM : 0)); + if (error) { + log_warnx("malformed bind address host \"%s\": %s", + host, gai_strerror(error)); + strlcpy(hostname, hostname_unknown, sizeof(hostname)); + strlcpy(servname, hostname_unknown, sizeof(servname)); } if (shutread && shutdown(*fdp, SHUT_RD) == -1) { log_warn("shutdown SHUT_RD " @@ -1130,7 +1138,7 @@ acceptcb(int lfd, short event, void *arg, int usetls) socklen_t sslen; char hostname[NI_MAXHOST], servname[NI_MAXSERV]; char *peername; - int fd; + int fd, error; sslen = sizeof(ss); if ((fd = reserve_accept4(lfd, event, ev, tcp_acceptcb, @@ -1143,17 +1151,21 @@ acceptcb(int lfd, short event, void *arg, int usetls) } log_debug("Accepting tcp connection"); - if (getnameinfo((struct sockaddr *)&ss, sslen, hostname, + error = getnameinfo((struct sockaddr *)&ss, sslen, hostname, sizeof(hostname), servname, sizeof(servname), - NI_NUMERICHOST | NI_NUMERICSERV) != 0 || - asprintf(&peername, ss.ss_family == AF_INET6 ? + NI_NUMERICHOST | NI_NUMERICSERV); + if (error) { + log_warnx("malformed TCP accept address: %s", + gai_strerror(error)); + peername = hostname_unknown; + } else if (asprintf(&peername, ss.ss_family == AF_INET6 ? "[%s]:%s" : "%s:%s", hostname, servname) == -1) { - log_debug("Malformed accept address"); + log_warn("allocate hostname \"%s\"", hostname); peername = hostname_unknown; } log_debug("Peer address and port %s", peername); if ((p = malloc(sizeof(*p))) == NULL) { - log_warn("allocate \"%s\"", peername); + log_warn("allocate peername \"%s\"", peername); close(fd); return; } @@ -1380,7 +1392,7 @@ tcp_writecb(struct bufferevent *bufev, void *arg) * Successful write, connection to server is good, reset wait time. */ log_debug("loghost \"%s\" successful write", f->f_un.f_forw.f_loghost); - f->f_un.f_forw.f_reconnectwait = 0; + f->f_un.f_forw.f_retrywait = 0; if (f->f_dropped > 0 && EVBUFFER_LENGTH(f->f_un.f_forw.f_bufev->output) < MAX_TCPBUF) { @@ -1440,7 +1452,7 @@ tcp_errorcb(struct bufferevent *bufev, short event, void *arg) f->f_dropped++; } - tcp_connect_retry(bufev, f); + loghost_retry(f); /* Log the connection error to the fresh buffer after reconnecting. */ log_info(LOG_WARNING, "%s", ebuf); @@ -1453,8 +1465,15 @@ tcp_connectcb(int fd, short event, void *arg) struct bufferevent *bufev = f->f_un.f_forw.f_bufev; int s; + if (f->f_un.f_forw.f_addr.ss_family == AF_UNSPEC) { + if (loghost_resolve(f) != 0) { + loghost_retry(f); + return; + } + } + if ((s = tcp_socket(f)) == -1) { - tcp_connect_retry(bufev, f); + loghost_retry(f); return; } log_debug("tcp connect callback: socket success, event %#x", event); @@ -1503,29 +1522,87 @@ tcp_connectcb(int fd, short event, void *arg) } close(f->f_file); f->f_file = -1; - tcp_connect_retry(bufev, f); + loghost_retry(f); +} + +int +loghost_resolve(struct filed *f) +{ + char hostname[NI_MAXHOST]; + int error; + + error = priv_getaddrinfo(f->f_un.f_forw.f_ipproto, + f->f_un.f_forw.f_host, f->f_un.f_forw.f_port, + (struct sockaddr *)&f->f_un.f_forw.f_addr, + sizeof(f->f_un.f_forw.f_addr)); + if (error) { + log_warnx("bad hostname \"%s\"", f->f_un.f_forw.f_loghost); + f->f_un.f_forw.f_addr.ss_family = AF_UNSPEC; + return (error); + } + + error = getnameinfo((struct sockaddr *)&f->f_un.f_forw.f_addr, + f->f_un.f_forw.f_addr.ss_len, hostname, sizeof(hostname), NULL, 0, + NI_NUMERICHOST | NI_NUMERICSERV | + (strncmp(f->f_un.f_forw.f_ipproto, "udp", 3) == 0 ? NI_DGRAM : 0)); + if (error) { + log_warnx("malformed UDP address loghost \"%s\": %s", + f->f_un.f_forw.f_loghost, gai_strerror(error)); + strlcpy(hostname, hostname_unknown, sizeof(hostname)); + } + + log_debug("resolved loghost \"%s\" address %s", + f->f_un.f_forw.f_loghost, hostname); + return (0); } void -tcp_connect_retry(struct bufferevent *bufev, struct filed *f) +loghost_retry(struct filed *f) { struct timeval to; - if (f->f_un.f_forw.f_reconnectwait == 0) - f->f_un.f_forw.f_reconnectwait = 1; + if (f->f_un.f_forw.f_retrywait == 0) + f->f_un.f_forw.f_retrywait = 1; else - f->f_un.f_forw.f_reconnectwait <<= 1; - if (f->f_un.f_forw.f_reconnectwait > 600) - f->f_un.f_forw.f_reconnectwait = 600; - to.tv_sec = f->f_un.f_forw.f_reconnectwait; + f->f_un.f_forw.f_retrywait <<= 1; + if (f->f_un.f_forw.f_retrywait > 600) + f->f_un.f_forw.f_retrywait = 600; + to.tv_sec = f->f_un.f_forw.f_retrywait; to.tv_usec = 0; + evtimer_add(&f->f_un.f_forw.f_ev, &to); + + log_debug("retry loghost \"%s\" wait %d", + f->f_un.f_forw.f_loghost, f->f_un.f_forw.f_retrywait); +} + +void +udp_resolvecb(int fd, short event, void *arg) +{ + struct filed *f = arg; + struct timeval to; + + if (loghost_resolve(f) != 0) { + loghost_retry(f); + return; + } + + switch (f->f_un.f_forw.f_addr.ss_family) { + case AF_INET: + f->f_file = fd_udp; + break; + case AF_INET6: + f->f_file = fd_udp6; + break; + } + f->f_un.f_forw.f_retrywait = 0; - log_debug("tcp connect retry: wait %d", - f->f_un.f_forw.f_reconnectwait); - bufferevent_setfd(bufev, -1); - /* We can reuse the write event as bufferevent is disabled. */ - evtimer_set(&bufev->ev_write, tcp_connectcb, f); - evtimer_add(&bufev->ev_write, &to); + if (f->f_dropped > 0) { + char ebuf[ERRBUFSIZE]; + + snprintf(ebuf, sizeof(ebuf), "to udp loghost \"%s\"", + f->f_un.f_forw.f_loghost); + dropped_warn(&f->f_dropped, ebuf); + } } int @@ -1933,6 +2010,11 @@ fprintlog(struct filed *f, int flags, char *msg) case F_FORWUDP: log_debug(" %s", f->f_un.f_forw.f_loghost); + if (f->f_un.f_forw.f_addr.ss_family == AF_UNSPEC) { + log_warnx("not resolved \"%s\"", + f->f_un.f_forw.f_loghost); + break; + } l = iov[0].iov_len + iov[1].iov_len + iov[2].iov_len + iov[3].iov_len + iov[4].iov_len + iov[5].iov_len + iov[6].iov_len; @@ -2168,9 +2250,13 @@ wallmsg(struct filed *f, struct iovec *iov) void cvthname(struct sockaddr *f, char *result, size_t res_len) { - if (getnameinfo(f, f->sa_len, result, res_len, NULL, 0, - NI_NUMERICHOST|NI_NUMERICSERV|NI_DGRAM) != 0) { - log_debug("Malformed from address"); + int error; + + error = getnameinfo(f, f->sa_len, result, res_len, NULL, 0, + NI_NUMERICHOST | NI_NUMERICSERV | NI_DGRAM); + if (error) { + log_warnx("malformed UDP from address: %s", + gai_strerror(error)); strlcpy(result, hostname_unknown, res_len); return; } @@ -2295,23 +2381,33 @@ init(void) fprintlog(f, 0, (char *)NULL); switch (f->f_type) { + case F_FORWUDP: + evtimer_del(&f->f_un.f_forw.f_ev); + free(f->f_un.f_forw.f_ipproto); + free(f->f_un.f_forw.f_host); + free(f->f_un.f_forw.f_port); + break; case F_FORWTLS: if (f->f_un.f_forw.f_ctx) { tls_close(f->f_un.f_forw.f_ctx); tls_free(f->f_un.f_forw.f_ctx); } - free(f->f_un.f_forw.f_host); /* FALLTHROUGH */ case F_FORWTCP: + evtimer_del(&f->f_un.f_forw.f_ev); tcpbuf_dropped += f->f_dropped + tcpbuf_countmsg(f->f_un.f_forw.f_bufev); bufferevent_free(f->f_un.f_forw.f_bufev); + free(f->f_un.f_forw.f_ipproto); + free(f->f_un.f_forw.f_host); + free(f->f_un.f_forw.f_port); /* FALLTHROUGH */ case F_FILE: if (f->f_type == F_FILE) { file_dropped += f->f_dropped; f->f_dropped = 0; } + /* FALLTHROUGH */ case F_TTY: case F_CONSOLE: case F_PIPE: @@ -2704,16 +2800,31 @@ cfline(char *line, char *progblock, char *hostblock) f->f_un.f_forw.f_loghost); break; } - if (priv_getaddrinfo(ipproto, host, port, - (struct sockaddr*)&f->f_un.f_forw.f_addr, - sizeof(f->f_un.f_forw.f_addr)) != 0) { - log_warnx("bad hostname \"%s\"", + f->f_un.f_forw.f_ipproto = strdup(ipproto); + f->f_un.f_forw.f_host = strdup(host); + f->f_un.f_forw.f_port = strdup(port); + if (f->f_un.f_forw.f_ipproto == NULL || + f->f_un.f_forw.f_host == NULL || + f->f_un.f_forw.f_port == NULL) { + log_warnx("strdup ipproto host port \"%s\"", f->f_un.f_forw.f_loghost); + free(f->f_un.f_forw.f_ipproto); + free(f->f_un.f_forw.f_host); + free(f->f_un.f_forw.f_port); break; } f->f_file = -1; + loghost_resolve(f); if (strncmp(proto, "udp", 3) == 0) { + evtimer_set(&f->f_un.f_forw.f_ev, udp_resolvecb, f); switch (f->f_un.f_forw.f_addr.ss_family) { + case AF_UNSPEC: + log_debug("resolve \"%s\" delayed", + f->f_un.f_forw.f_loghost); + to.tv_sec = 0; + to.tv_usec = 1; + evtimer_add(&f->f_un.f_forw.f_ev, &to); + break; case AF_INET: f->f_file = fd_udp; break; @@ -2727,26 +2838,23 @@ cfline(char *line, char *progblock, char *hostblock) tcp_dropcb, tcp_writecb, tcp_errorcb, f)) == NULL) { log_warn("bufferevent \"%s\"", f->f_un.f_forw.f_loghost); + free(f->f_un.f_forw.f_ipproto); + free(f->f_un.f_forw.f_host); + free(f->f_un.f_forw.f_port); break; } - if (strncmp(proto, "tls", 3) == 0) { - f->f_un.f_forw.f_host = strdup(host); - f->f_type = F_FORWTLS; - } else { - f->f_type = F_FORWTCP; - } /* * If we try to connect to a TLS server immediately * syslogd gets an SIGPIPE as the signal handlers have * not been set up. Delay the connection until the - * event loop is started. We can reuse the write event - * for that as bufferevent is still disabled. + * event loop is started. */ + evtimer_set(&f->f_un.f_forw.f_ev, tcp_connectcb, f); to.tv_sec = 0; to.tv_usec = 1; - evtimer_set(&f->f_un.f_forw.f_bufev->ev_write, - tcp_connectcb, f); - evtimer_add(&f->f_un.f_forw.f_bufev->ev_write, &to); + evtimer_add(&f->f_un.f_forw.f_ev, &to); + f->f_type = (strncmp(proto, "tls", 3) == 0) ? + F_FORWTLS : F_FORWTCP; } break; diff --git a/usr.sbin/syslogd/syslogd.h b/usr.sbin/syslogd/syslogd.h index f483beb52cf..0ff88cb3835 100644 --- a/usr.sbin/syslogd/syslogd.h +++ b/usr.sbin/syslogd/syslogd.h @@ -1,4 +1,4 @@ -/* $OpenBSD: syslogd.h,v 1.36 2022/01/13 10:34:07 martijn Exp $ */ +/* $OpenBSD: syslogd.h,v 1.37 2023/10/12 22:36:54 bluhm Exp $ */ /* * Copyright (c) 2014-2017 Alexander Bluhm @@ -34,7 +34,8 @@ FILE *priv_open_utmp(void); FILE *priv_open_config(void); void priv_config_parse_done(void); int priv_config_modified(void); -int priv_getaddrinfo(char *, char *, char *, struct sockaddr *, size_t); +int priv_getaddrinfo(const char *, const char *, const char *, + struct sockaddr *, size_t); int priv_getnameinfo(struct sockaddr *, socklen_t, char *, size_t); #define IOVCNT 7 -- 2.20.1