Make log messages more informative by using the

name of the function that failed and the significant
parameters. Distinguish between poll() errors and
problematic revents values.

4 files changed, 42 insertions, 39 deletions

diff --git a/sbin/dhclient/bpf.c b/sbin/dhclient/bpf.c
index c3e2405c11d..4416d8f39e9 100644
--- a/sbin/dhclient/bpf.c
+++ b/sbin/dhclient/bpf.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: bpf.c,v 1.68 2017/09/20 15:14:52 krw Exp $	*/
+/*	$OpenBSD: bpf.c,v 1.69 2017/09/20 18:28:14 krw Exp $	*/
 
 /* BPF socket interface code, originally contributed by Archie Cobbs. */
 
@@ -336,7 +336,8 @@ receive_packet(struct interface_info *ifi, struct sockaddr_in *from,
 {
 	struct bpf_hdr		 hdr;
 	struct dhcp_packet	*packet = &ifi->recv_packet;
-	int			 length = 0, offset = 0;
+	ssize_t			 length = 0;
+	int			 offset = 0;
 
 	/*
 	 * All this complexity is because BPF doesn't guarantee that
@@ -352,8 +353,11 @@ receive_packet(struct interface_info *ifi, struct sockaddr_in *from,
 		/* If the buffer is empty, fill it. */
 		if (ifi->rbuf_offset >= ifi->rbuf_len) {
 			length = read(ifi->bfdesc, ifi->rbuf, ifi->rbuf_max);
-			if (length <= 0)
-				return  length ;
+			if (length == -1) {
+				log_warn("%s: read(bfdesc)", log_procname);
+				return length;
+			} else if (length == 0)
+				return length;
 			ifi->rbuf_offset = 0;
 			ifi->rbuf_len = length;
 		}
diff --git a/sbin/dhclient/dhclient.c b/sbin/dhclient/dhclient.c
index 062964e94f4..e4dc2b958a1 100644
--- a/sbin/dhclient/dhclient.c
+++ b/sbin/dhclient/dhclient.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: dhclient.c,v 1.507 2017/09/20 16:09:42 krw Exp $	*/
+/*	$OpenBSD: dhclient.c,v 1.508 2017/09/20 18:28:14 krw Exp $	*/
 
 /*
  * Copyright 2004 Henning Brauer <henning@openbsd.org>
@@ -2152,7 +2152,7 @@ fork_privchld(struct interface_info *ifi, int fd, int fd2)
 		if (nfds == -1) {
 			if (errno == EINTR)
 				continue;
-			log_warn("%s: priv_ibuf poll", log_procname);
+			log_warn("%s: poll(priv_ibuf)", log_procname);
 			quit = INTERNALSIG;
 			continue;
 		}
diff --git a/sbin/dhclient/dispatch.c b/sbin/dhclient/dispatch.c
index fd3ef69c1e4..aff71a2b471 100644
--- a/sbin/dhclient/dispatch.c
+++ b/sbin/dhclient/dispatch.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: dispatch.c,v 1.144 2017/09/20 15:31:29 krw Exp $	*/
+/*	$OpenBSD: dispatch.c,v 1.145 2017/09/20 18:28:14 krw Exp $	*/
 
 /*
  * Copyright 2004 Henning Brauer <henning@openbsd.org>
@@ -130,23 +130,24 @@ dispatch(struct interface_info *ifi, int routefd)
 		if (nfds == -1) {
 			if (errno == EINTR)
 				continue;
-			log_warn("%s: dispatch poll", log_procname);
+			log_warn("%s: poll(bfdesc, routefd, unpriv_ibuf)",
+			    log_procname);
 			quit = INTERNALSIG;
 			continue;
 		}
 
 		if ((fds[0].revents & (POLLERR | POLLHUP | POLLNVAL)) != 0) {
-			log_warnx("%s: bfdesc poll error", log_procname);
+			log_warnx("%s: bfdesc: ERR|HUP|NVAL", log_procname);
 			quit = INTERNALSIG;
 			continue;
 		}
 		if ((fds[1].revents & (POLLERR | POLLHUP | POLLNVAL)) != 0) {
-			log_warnx("%s: routefd poll error", log_procname);
+			log_warnx("%s: routefd: ERR|HUP|NVAL", log_procname);
 			quit = INTERNALSIG;
 			continue;
 		}
 		if ((fds[2].revents & (POLLERR | POLLHUP | POLLNVAL)) != 0) {
-			log_warnx("%s: unpriv_ibuf poll error", log_procname);
+			log_warnx("%s: unpriv_ibuf: ERR|HUP|NVAL", log_procname);
 			quit = INTERNALSIG;
 			continue;
 		}
@@ -186,12 +187,11 @@ packethandler(struct interface_info *ifi)
 	    struct option_data *, char *);
 	int			 i, rslt;
 
-	if ((result = receive_packet(ifi, &from, &hfrom)) == -1) {
+	result = receive_packet(ifi, &from, &hfrom);
+	if (result == -1) {
 		ifi->errors++;
 		if (ifi->errors > 20)
 			fatalx("too many receive_packet failures");
-		else
-			log_warn("%s receive_packet failed", log_procname);
 		return;
 	}
 	ifi->errors = 0;
@@ -346,5 +346,5 @@ sendhup(void)
 
 	rslt = imsg_compose(unpriv_ibuf, IMSG_HUP, 0, 0, -1, NULL, 0);
 	if (rslt == -1)
-		log_warn("%s: sendhup: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_HUP)", log_procname);
 }
diff --git a/sbin/dhclient/kroute.c b/sbin/dhclient/kroute.c
index 6f6bf4c1ba3..4bbc2a38b76 100644
--- a/sbin/dhclient/kroute.c
+++ b/sbin/dhclient/kroute.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: kroute.c,v 1.151 2017/09/20 16:34:29 krw Exp $	*/
+/*	$OpenBSD: kroute.c,v 1.152 2017/09/20 18:28:14 krw Exp $	*/
 
 /*
  * Copyright 2012 Kenneth R Westerback <krw@openbsd.org>
@@ -130,7 +130,7 @@ flush_routes(uint8_t *rtstatic, unsigned int rtstatic_len)
 	rslt = imsg_compose(unpriv_ibuf, IMSG_FLUSH_ROUTES, 0, 0, -1, &imsg,
 	    sizeof(imsg));
 	if (rslt == -1)
-		log_warn("%s: flush_routes: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_FLUSH_ROUTES)", log_procname);
 }
 
 void
@@ -174,10 +174,10 @@ priv_flush_routes(int index, int routefd, int rdomain,
 		rlen = write(routefd, (char *)rtm, rtm->rtm_msglen);
 		if (rlen == -1) {
 			if (errno != ESRCH)
-				log_warn("%s: RTM_DELETE write", log_procname);
+				log_warn("%s: write(RTM_DELETE)", log_procname);
 		} else if (rlen < (int)rtm->rtm_msglen)
-			log_warnx("%s: short RTM_DELETE write (%zd)",
-			    log_procname, rlen);
+			log_warnx("%s: write(RTM_DELETE): %zd of %u bytes",
+			    log_procname, rlen, rtm->rtm_msglen);
 	}
 
 	free(buf);
@@ -310,7 +310,7 @@ add_route(struct in_addr dest, struct in_addr netmask, struct in_addr gateway,
 	rslt = imsg_compose(unpriv_ibuf, IMSG_ADD_ROUTE, 0, 0, -1,
 	    &imsg, sizeof(imsg));
 	if (rslt == -1)
-		log_warn("%s: add_route: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_ADD_ROUTE)", log_procname);
 }
 
 void
@@ -445,7 +445,7 @@ delete_address(struct in_addr addr)
 	rslt = imsg_compose(unpriv_ibuf, IMSG_DELETE_ADDRESS, 0, 0 , -1, &imsg,
 	    sizeof(imsg));
 	if (rslt == -1)
-		log_warn("%s: delete_address: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_DELETE_ADDRESS)", log_procname);
 }
 
 void
@@ -497,7 +497,7 @@ set_mtu(int inits, uint16_t mtu)
 	rslt = imsg_compose(unpriv_ibuf, IMSG_SET_MTU, 0, 0, -1,
 	    &imsg, sizeof(imsg));
 	if (rslt == -1)
-		log_warn("%s: set_mtu: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_SET_MTU)", log_procname);
 }
 
 void
@@ -535,7 +535,7 @@ set_address(char *name, struct in_addr addr, struct in_addr netmask)
 	rslt = imsg_compose(unpriv_ibuf, IMSG_SET_ADDRESS, 0, 0, -1, &imsg,
 	    sizeof(imsg));
 	if (rslt == -1)
-		log_warn("%s: set_address: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_SET_ADDRESS)", log_procname);
 }
 
 void
@@ -577,7 +577,8 @@ write_resolv_conf(void)
 	rslt = imsg_compose(unpriv_ibuf, IMSG_WRITE_RESOLV_CONF,
 	    0, 0, -1, NULL, 0);
 	if (rslt == -1)
-		log_warn("%s: write_resolv_conf: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_WRITE_RESOLV_CONF)",
+		    log_procname);
 }
 
 void
@@ -595,18 +596,17 @@ priv_write_resolv_conf(char *contents)
 	    S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH);
 
 	if (fd == -1) {
-		log_warn("%s: couldn't open '%s'", log_procname, path);
+		log_warn("%s: open(%s)", log_procname, path);
 		return;
 	}
 
 	sz = strlen(contents);
 	n = write(fd, contents, sz);
 	if (n == -1)
-		log_warn("%s: couldn't write contents to '%s'", log_procname,
-		    path);
+		log_warn("%s: write(%s)", log_procname, path);
 	else if ((size_t)n < sz)
-		log_warnx("%s: short contents write to '%s' (%zd vs %zu)",
-		    log_procname, path, n, sz);
+		log_warnx("%s: write(%s): %zd of %zu bytes", log_procname,
+		    path, n, sz);
 
 	close(fd);
 }
@@ -656,7 +656,7 @@ default_route_index(int rdomain, int routefd)
 		fatal("start time");
 
 	if (writev(routefd, iov, 3) == -1) {
-		log_warn("%s: RTM_GET of default route", log_procname);
+		log_warn("%s: writev(RTM_GET)", log_procname);
 		return 0;
 	}
 
@@ -669,11 +669,11 @@ default_route_index(int rdomain, int routefd)
 		if (nfds == -1) {
 			if (errno == EINTR)
 				continue;
-			log_warn("%s: default route poll", log_procname);
+			log_warn("%s: poll(routefd)", log_procname);
 			break;
 		}
 		if ((fds[0].revents & (POLLERR | POLLHUP | POLLNVAL)) != 0) {
-			log_warnx("%s: default route revents", log_procname);
+			log_warnx("%s: routefd: ERR|HUP|NVAL", log_procname);
 			break;
 		}
 		if (nfds == 0 || (fds[0].revents & POLLIN) == 0)
@@ -681,11 +681,10 @@ default_route_index(int rdomain, int routefd)
 
 		len = read(routefd, &m_rtmsg, sizeof(m_rtmsg));
 		if (len == -1) {
-			log_warn("%s: get default route read", log_procname);
+			log_warn("%s: read(RTM_GET)", log_procname);
 			break;
 		} else if (len == 0) {
-			log_warnx("%s: no data from default route read",
-			    log_procname);
+			log_warnx("%s: read(RTM_GET): 0 bytes", log_procname);
 			break;
 		}
 
@@ -694,8 +693,7 @@ default_route_index(int rdomain, int routefd)
 		    m_rtmsg.m_rtm.rtm_pid == pid &&
 		    m_rtmsg.m_rtm.rtm_seq == seq) {
 			if (m_rtmsg.m_rtm.rtm_errno != 0) {
-				log_warnx("%s: route read rtm: %s",
-				    log_procname, 
+				log_warnx("%s: read(RTM_GET): %s", log_procname,
 				    strerror(m_rtmsg.m_rtm.rtm_errno));
 				break;
 			}
@@ -794,7 +792,8 @@ done:
 	rslt = imsg_compose(unpriv_ibuf, IMSG_SET_RESOLV_CONF,
 	    0, 0, -1, contents, len);
 	if (rslt == -1)
-		log_warn("%s: resolv_conf: imsg_compose", log_procname);
+		log_warn("%s: imsg_compose(IMSG_SET_RESOLV_CONF)",
+		    log_procname);
 }
 
 /*