syslogd: Handle connection errors when setting up forwarding sockets

Since syslogd was converted to run in a Capsicum sandbox, it needs to
explicitly connect() its forwarding sockets rather than using sendmsg().
At the time syslogd starts during boot, some of its forwarding
destinations may not be routable, in which case connect() fails.

Fix this by making connect() failures non-fatal, and use cap_net to
lazily connect sockets once something actually tries logging to the
destination.

Add a regression test.

Reported by:	ae
Reviewed by:	ae
Discussed with:	jfree
Fixes:		4ecbee2760 ("syslogd: Open forwarding socket descriptors")
MFC after:	2 weeks
Differential Revision:	https://reviews.freebsd.org/D57394

usr.sbin/syslogd/syslogd.c

@@ -1752,6 +1752,24 @@ iovlist_truncate(struct iovlist *il, size_t size)
 }
 #endif
 
+static int
+find_forw_fd(const struct sockaddr_storage *rss,
+    const struct sockaddr_storage *lss, struct filed *skip)
+{
+	struct filed *f;
+
+	STAILQ_FOREACH(f, &fhead, next) {
+		if (f->f_type != F_FORW || f == skip)
+			continue;
+		for (size_t i = 0; i < f->f_num_addr_fds; ++i) {
+			if (memcmp(&f->f_addrs[i].raddr, rss, rss->ss_len) == 0 &&
+			    memcmp(&f->f_addrs[i].laddr, lss, lss->ss_len) == 0)
+				return (f->f_addr_fds[i]);
+		}
+	}
+	return (-1);
+}
+
 static void
 fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 {
@@ -1760,13 +1778,14 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 		ssize_t lsent;
 
 		if (Debug) {
-			int domain, sockfd = f->f_addr_fds[0];
+			int domain, port, sockfd = f->f_addr_fds[0];
 			socklen_t len = sizeof(domain);
 
 			if (getsockopt(sockfd, SOL_SOCKET, SO_DOMAIN,
 			    &domain, &len) < 0)
 				err(1, "getsockopt");
 
+			port = -1;
 			printf(" %s", f->f_hname);
 			switch (domain) {
 #ifdef INET
@@ -1776,8 +1795,10 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 				len = sizeof(sin);
 				if (getpeername(sockfd,
 				    (struct sockaddr *)&sin, &len) < 0)
-					err(1, "getpeername");
-				printf(":%d\n", ntohs(sin.sin_port));
+					warn("getpeername");
+				else
+					port = ntohs(sin.sin_port);
+				printf(":%d\n", port);
 				break;
 			}
 #endif
@@ -1788,8 +1809,10 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 				len = sizeof(sin6);
 				if (getpeername(sockfd,
 				    (struct sockaddr *)&sin6, &len) < 0)
-					err(1, "getpeername");
-				printf(":%d\n", ntohs(sin6.sin6_port));
+					warn("getpeername");
+				else
+					port = ntohs(sin6.sin6_port);
+				printf(":%d\n", port);
 				break;
 			}
 #endif
@@ -1803,23 +1826,76 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 		iovlist_truncate(il, MaxForwardLen);
 #endif
 
+		/*
+		 * We have some constraints on message forwarding:
+		 * - we want to send messages from an address to which syslogd
+		 *   is bound,
+		 * - syslogd might start before the system's routes are
+		 *   configured, in which case connect() will fail,
+		 * - there may be multiple logging rules which forward a message
+		 *   to a given address, i.e., sockets from different fileds
+		 *   may have the same <laddr, raddr> tuple,
+		 * - we don't want to use casper to forward messages for us, as
+		 *   that's a lot of overhead to add to each message.
+		 *
+		 * These constraints plus Capsicum's restrictions make this
+		 * rather complicated.  We handle the first constraint by
+		 * calling bind() when setting up forwarding sockets.  The
+		 * second constraint is handled by allowing connect() to fail
+		 * during setup; if the sendmsg() call below fails for that
+		 * reason, we then use cap_connect() to connect it lazily.
+		 * Finally, that connect() call may fail due to the third
+		 * constraint, in which case we look for another matching socket
+		 * and use that one instead.
+		 */
 		lsent = 0;
 		for (size_t i = 0; i < f->f_num_addr_fds; ++i) {
 			struct msghdr msg = {
 				.msg_iov = il->iov,
 				.msg_iovlen = il->iovcnt,
 			};
+			int fd;
 
-			lsent = sendmsg(f->f_addr_fds[i], &msg, 0);
+			fd = f->f_addr_fds[i];
+			lsent = sendmsg(fd, &msg, 0);
+			if (lsent == -1 &&
+			    (errno == ENOTCONN || errno == EDESTADDRREQ)) {
+				int error;
+
+				error = cap_connect(cap_net, fd,
+				    (struct sockaddr *)&f->f_addrs[i].raddr,
+				    f->f_addrs[i].raddr.ss_len);
+				if (error != 0 && errno == EADDRINUSE) {
+					fd = find_forw_fd(&f->f_addrs[i].raddr,
+					    &f->f_addrs[i].laddr, f);
+					if (fd != -1) {
+						(void)dup2(fd,
+						    f->f_addr_fds[i]);
+						fd = f->f_addr_fds[i];
+					} else {
+						/*
+						 * Something is preventing us
+						 * from connecting, we don't
+						 * have much recourse.  Keep
+						 * fd==-1 to trigger an error
+						 * from sendmsg() below.
+						 */
+						dprintf(
+						    "failed to connect to %s",
+						    f->f_hname);
+					}
+				}
+				lsent = sendmsg(fd, &msg, 0);
+			}
 			if (lsent == (ssize_t)il->totalsize && !send_to_all)
 				break;
 		}
 		dprintf("lsent/totalsize: %zd/%zu\n", lsent, il->totalsize);
 		if (lsent != (ssize_t)il->totalsize) {
 			int e = errno;
+
 			logerror("sendto");
-			errno = e;
-			switch (errno) {
+			switch (e) {
 			case ENOBUFS:
 			case ENETDOWN:
 			case ENETUNREACH:
@@ -1828,6 +1904,9 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 			case EADDRNOTAVAIL:
 			case EAGAIN:
 			case ECONNREFUSED:
+			case ENOTCONN:
+			case EDESTADDRREQ:
+			case EADDRINUSE:
 				break;
 			/* case EBADF: */
 			/* case EACCES: */
@@ -1836,7 +1915,7 @@ fprintlog_write(struct filed *f, struct iovlist *il, int flags)
 			/* case EMSGSIZE: */
 			default:
 				dprintf("removing entry: errno=%d\n", e);
-				f->f_type = F_UNUSED;
+				close_filed(f);
 				break;
 			}
 		}
@@ -2533,7 +2612,7 @@ syslogd_cap_enter(void)
 		err(1, "Failed to open the system.net libcasper service");
 	cap_close(cap_casper);
 	limit = cap_net_limit_init(cap_net,
-	    CAPNET_ADDR2NAME | CAPNET_NAME2ADDR);
+	    CAPNET_ADDR2NAME | CAPNET_NAME2ADDR | CAPNET_CONNECT);
 	if (limit == NULL)
 		err(1, "Failed to create system.net limits");
 	if (cap_net_limit(limit) == -1)
@@ -2641,15 +2720,18 @@ init(bool reload)
 				    &domain, &len) < 0)
 					err(1, "getsockopt");
 
+				port = -1;
 				switch (domain) {
 #ifdef INET
 				case AF_INET: {
 					struct sockaddr_in sin;
 
 					len = sizeof(sin);
-					if (getpeername(sockfd, (struct sockaddr *)&sin, &len) < 0)
-						err(1, "getpeername");
-					port = ntohs(sin.sin_port);
+					if (getpeername(sockfd,
+					    (struct sockaddr *)&sin, &len) < 0)
+						warn("getpeername");
+					else
+						port = ntohs(sin.sin_port);
 					break;
 				}
 #endif
@@ -2658,20 +2740,18 @@ init(bool reload)
 					struct sockaddr_in6 sin6;
 
 					len = sizeof(sin6);
-					if (getpeername(sockfd, (struct sockaddr *)&sin6, &len) < 0)
-						err(1, "getpeername");
-					port = ntohs(sin6.sin6_port);
+					if (getpeername(sockfd,
+					    (struct sockaddr *)&sin6, &len) < 0)
+						warn("getpeername");
+					else
+						port = ntohs(sin6.sin6_port);
 					break;
 				}
 #endif
 				default:
 					port = 0;
 				}
-				if (port != 514) {
-					printf("%s:%d", f->f_hname, port);
-				} else {
-					printf("%s", f->f_hname);
-				}
+				printf("%s:%d", f->f_hname, port);
 				break;
 			}
 
@@ -3014,13 +3094,20 @@ make_forw_socket(const nvlist_t *nvl, struct addrinfo *ai, struct addrinfo *lai)
 				errc(1, EADDRINUSE, "connect");
 			(void)close(s);
 			s = s1;
+		} else if (errno == ENETUNREACH || errno == EHOSTUNREACH) {
+			/*
+			 * We can't connect right now, the system is probably
+			 * not fully configured.  We will try again, using
+			 * cap_net, once something actually tries to log.
+			 */
+			;
 		} else {
 			err(1, "connect");
 		}
 	}
 	/* Make it a write-only socket. */
 	if (shutdown(s, SHUT_RD) < 0)
-		err(1, "shutdown");
+		warn("shutdown");
 
 	return (s);
 }
@@ -3144,7 +3231,8 @@ parse_action(const nvlist_t *nvl, const char *p, struct filed *f)
 		};
 		error = getaddrinfo(f->f_hname, p ? p : "syslog", &hints, &res);
 		if (error) {
-			dprintf("%s\n", gai_strerror(error));
+			dprintf("getaddrinfo(%s): %s\n", f->f_hname,
+			    gai_strerror(error));
 			break;
 		}
 		make_forw_socket_array(nvl, f, res);

usr.sbin/syslogd/syslogd_cap_config.c

@@ -226,6 +226,13 @@ nvlist_to_filed(const nvlist_t *nvl_filed)
 			if (filed->f_addr_fds[i] < 0)
 				err(1, "dup");
 		}
+		filed->f_addrs = calloc(filed->f_num_addr_fds,
+		    sizeof(*filed->f_addrs));
+		if (filed->f_addrs == NULL)
+			err(1, "calloc");
+		memcpy(filed->f_addrs,
+		    nvlist_get_binary(nvl_filed, "f_addrs", NULL),
+		    filed->f_num_addr_fds * sizeof(*filed->f_addrs));
 	} else if (filed->f_type == F_PIPE) {
 		(void)strlcpy(filed->f_pname, nvlist_get_string(nvl_filed,
 		    "f_pname"), sizeof(filed->f_pname));

usr.sbin/syslogd/tests/Makefile

@@ -7,8 +7,7 @@ ATF_TESTS_SH=	syslogd_basic_format_test \
 
 # Run in jail with new vnet so we don't need to worry about address conflicts
 TEST_METADATA=	execenv="jail" \
-		execenv_jail_params="vnet=new" \
-		timeout=20
+		execenv_jail_params="vnet=new"
 
 ${PACKAGE}FILES=syslogd_format_test_common.sh \
 		syslogd_test_common.sh

usr.sbin/syslogd/tests/syslogd_test.sh

@@ -588,6 +588,74 @@ forward_cleanup()
     syslogd_cleanup
 }
 
+atf_test_case "forward_reload" "cleanup"
+forward_reload_head()
+{
+    atf_set descr "syslogd might start before routes are configured"
+    atf_set require.user root
+}
+forward_reload_body()
+{
+    local epair server client
+
+    server=syslogd_server$$
+    client=syslogd_client$$
+
+    syslogd_check_req epair
+
+    atf_check -o save:epair ifconfig epair create
+    epair=$(cat epair)
+    epair=${epair%%a}
+
+    syslogd_mkjail $server vnet
+    atf_check ifconfig ${epair}a vnet $server
+    atf_check jexec $server ifconfig ${epair}a inet6 fd00::2/64
+
+    syslogd_mkjail $client vnet
+    atf_check ifconfig ${epair}b vnet $client
+
+    cat <<__EOF__ > ./server_config
+user.debug ${SYSLOGD_LOGFILE}
+ftp.debug ${SYSLOGD_LOGFILE}
+__EOF__
+
+    syslogd_start -j $server -f ${PWD}/server_config -b fd00::2
+
+    cat <<__EOF__ > ./client_config
+user.debug @[fd00::2]
+ftp.debug @[fd00::2]
+__EOF__
+
+    syslogd_start -j $client -f ${PWD}/client_config \
+        -p ${PWD}/client -P ${SYSLOGD_PIDFILE}.2
+
+    # Make sure the client can't reach the server with the current
+    # network configuration.
+    atf_check -s not-exit:0 -e match:"No route to host" \
+        jexec $client ping6 -c 1 fd00::2
+
+    syslogd_log_jail $client -p user.debug -t test1 "hello there"
+    syslogd_log_jail $client -p ftp.debug -t test2 "hi there"
+
+    atf_check jexec $client ifconfig ${epair}b inet6 fd00::1/64
+    atf_check -o ignore jexec $client ping6 -c 1 fd00::2
+
+    syslogd_check_log_nomatch "test1: hello there"
+    syslogd_check_log_nomatch "test2: hi there"
+
+    syslogd_log_jail $client \
+        -p user.debug -t test1 -h ${PWD}/client "how about now"
+    syslogd_check_log "test1: how about now"
+
+    syslogd_log_jail $client \
+        -p ftp.debug -t test2 -h ${PWD}/client "bing bong"
+    syslogd_check_log "test2: bing bong"
+}
+forward_reload_cleanup()
+{
+    syslogd_cleanup
+}
+
 atf_init_test_cases()
 {
     atf_add_test_case "unix"
@@ -605,4 +673,5 @@ atf_init_test_cases()
     atf_add_test_case "allowed_peer_forwarding"
     atf_add_test_case "allowed_peer_wildcard"
     atf_add_test_case "forward"
+    atf_add_test_case "forward_reload"
 }