From e998cdbe84b5e13a79cce73f929ddf74819a5070 Mon Sep 17 00:00:00 2001 From: florian Date: Sun, 7 Mar 2021 18:39:11 +0000 Subject: [PATCH] Reduce debug logging by moving protocol level debug log behind -vv or by deleting unneeded output. While here reword some debug output to make it more useful. (There is more to be done here.) --- sbin/dhcpleased/dhcpleased.c | 19 ++- sbin/dhcpleased/engine.c | 258 +++++++++++++++++++++-------------- sbin/dhcpleased/frontend.c | 29 ++-- 3 files changed, 177 insertions(+), 129 deletions(-) diff --git a/sbin/dhcpleased/dhcpleased.c b/sbin/dhcpleased/dhcpleased.c index d2c936aab03..a71fcbedbd7 100644 --- a/sbin/dhcpleased/dhcpleased.c +++ b/sbin/dhcpleased/dhcpleased.c @@ -1,4 +1,4 @@ -/* $OpenBSD: dhcpleased.c,v 1.6 2021/03/02 12:03:50 florian Exp $ */ +/* $OpenBSD: dhcpleased.c,v 1.7 2021/03/07 18:39:11 florian Exp $ */ /* * Copyright (c) 2017, 2021 Florian Obser @@ -407,7 +407,6 @@ main_dispatch_frontend(int fd, short event, void *bula) switch (imsg.hdr.type) { case IMSG_OPEN_BPFSOCK: - log_debug("IMSG_OPEN_BPFSOCK"); if (IMSG_DATA_SIZE(imsg) != sizeof(if_index)) fatalx("%s: IMSG_OPEN_BPFSOCK wrong length: " "%lu", __func__, IMSG_DATA_SIZE(imsg)); @@ -627,8 +626,6 @@ configure_interface(struct imsg_configure_interface *imsg) IF_NAMESIZE]; char tmpl[] = _PATH_LEASE"XXXXXXXXXX"; - log_debug("%s", __func__); - memset(&ifaliasreq, 0, sizeof(ifaliasreq)); if_name = if_indextoname(imsg->if_index, ifaliasreq.ifra_name); @@ -638,6 +635,8 @@ configure_interface(struct imsg_configure_interface *imsg) return; } + log_debug("%s %s", __func__, if_name); + if (getifaddrs(&ifap) != 0) fatal("getifaddrs"); @@ -712,7 +711,7 @@ configure_interface(struct imsg_configure_interface *imsg) } shutdown(udpsock, SHUT_RD); - log_debug("%s: udpsock: %d", __func__, udpsock); + main_imsg_compose_frontend(IMSG_UDPSOCK, udpsock, &imsg->if_index, sizeof(imsg->if_index)); @@ -772,8 +771,6 @@ deconfigure_interface(struct imsg_configure_interface *imsg) struct ifaliasreq ifaliasreq; struct sockaddr_in *req_sin_addr; - log_debug("%s", __func__); - memset(&ifaliasreq, 0, sizeof(ifaliasreq)); if (imsg->router.s_addr != INADDR_ANY) @@ -785,6 +782,8 @@ deconfigure_interface(struct imsg_configure_interface *imsg) return; } + log_debug("%s %s", __func__, ifaliasreq.ifra_name); + req_sin_addr = (struct sockaddr_in *)&ifaliasreq.ifra_addr; req_sin_addr->sin_family = AF_INET; req_sin_addr->sin_len = sizeof(*req_sin_addr); @@ -906,9 +905,7 @@ open_bpfsock(uint32_t if_index) int bpfsock; char ifname[IF_NAMESIZE]; - log_debug("%s: %d", __func__, if_index); - - if (if_indextoname(if_index, ifname) == 0) { + if (if_indextoname(if_index, ifname) == NULL) { log_warnx("%s: cannot find interface %d", __func__, if_index); return; } @@ -975,7 +972,7 @@ read_lease_file(struct imsg_ifinfo *imsg_ifinfo) memset(imsg_ifinfo->lease, 0, sizeof(imsg_ifinfo->lease)); - if (if_indextoname(imsg_ifinfo->if_index, if_name) == 0) { + if (if_indextoname(imsg_ifinfo->if_index, if_name) == NULL) { log_warnx("%s: cannot find interface %d", __func__, imsg_ifinfo->if_index); return; diff --git a/sbin/dhcpleased/engine.c b/sbin/dhcpleased/engine.c index 91063b386f9..fbe7a78780f 100644 --- a/sbin/dhcpleased/engine.c +++ b/sbin/dhcpleased/engine.c @@ -1,4 +1,4 @@ -/* $OpenBSD: engine.c,v 1.8 2021/03/07 16:22:01 florian Exp $ */ +/* $OpenBSD: engine.c,v 1.9 2021/03/07 18:39:11 florian Exp $ */ /* * Copyright (c) 2017, 2021 Florian Obser @@ -137,6 +137,8 @@ void send_rdns_withdraw(struct dhcpleased_iface *); void parse_lease(struct dhcpleased_iface *, struct imsg_ifinfo *); int engine_imsg_compose_main(int, pid_t, void *, uint16_t); +void log_dhcp_hdr(struct dhcp_hdr *); +const char *dhcp_message_type2str(uint8_t); static struct imsgev *iev_frontend; static struct imsgev *iev_main; @@ -495,6 +497,7 @@ engine_showinfo_ctl(struct imsg *imsg, uint32_t if_index) } } #endif /* SMALL */ + void engine_update_iface(struct imsg_ifinfo *imsg_ifinfo) { @@ -606,6 +609,7 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) char hbuf_dst[INET_ADDRSTRLEN]; char hbuf[INET_ADDRSTRLEN]; char vis_buf[4 * 255 + 1]; + char ifnamebuf[IF_NAMESIZE], *if_name; if (bcast_mac.ether_addr_octet[0] == 0) memset(bcast_mac.ether_addr_octet, 0xff, ETHER_ADDR_LEN); @@ -637,7 +641,8 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) if (rem < sizeof(*ip)) goto too_short; - log_debug("%s, from: %s, to: %s", __func__, from, to); + if (log_getverbose() > 1) + log_debug("%s, from: %s, to: %s", __func__, from, to); ip = (struct ip *)p; @@ -657,7 +662,7 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) if (inet_ntop(AF_INET, &ip->ip_src, hbuf_src, sizeof(hbuf_src)) == NULL) hbuf_src[0] = '\0'; if (inet_ntop(AF_INET, &ip->ip_dst, hbuf_dst, sizeof(hbuf_dst)) == NULL) - hbuf_src[0] = '\0'; + hbuf_dst[0] = '\0'; if (rem < sizeof(*udp)) goto too_short; @@ -667,8 +672,11 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto too_short; if (rem > ntohs(udp->uh_ulen)) { - log_debug("%s: accepting packet with %lu bytes of data after " - "udp payload", __func__, rem - ntohs(udp->uh_ulen)); + if (log_getverbose() > 1) { + log_debug("%s: accepting packet with %lu bytes of data" + " after udp payload", __func__, rem - + ntohs(udp->uh_ulen)); + } rem = ntohs(udp->uh_ulen); } @@ -687,9 +695,10 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) return; } - log_debug("%s: %s:%d -> %s:%d", __func__, - hbuf_src, ntohs(udp->uh_sport), - hbuf_dst, ntohs(udp->uh_dport)); + if (log_getverbose() > 1) { + log_debug("%s: %s:%d -> %s:%d", __func__, hbuf_src, + ntohs(udp->uh_sport), hbuf_dst, ntohs(udp->uh_dport)); + } if (ntohs(udp->uh_sport) != SERVER_PORT || ntohs(udp->uh_dport) != CLIENT_PORT) { @@ -707,33 +716,9 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) dhcp_hdr->sname[DHCP_SNAME_LEN -1 ] = '\0'; /* ensure it's a string */ dhcp_hdr->file[DHCP_FILE_LEN -1 ] = '\0'; /* ensure it's a string */ - log_debug("dhcp_hdr op: %s (%d)", dhcp_hdr->op == DHCP_BOOTREQUEST ? - "Boot Request" : dhcp_hdr->op == DHCP_BOOTREPLY ? "Boot Reply" : - "Unknown", dhcp_hdr->op); - log_debug("dhcp_hdr htype: %s (%d)", dhcp_hdr->htype == 1 ? "Ethernet": - "Unknown", dhcp_hdr->htype); - log_debug("dhcp_hdr hlen: %d", dhcp_hdr->hlen); - log_debug("dhcp_hdr hops: %d", dhcp_hdr->hops); - log_debug("dhcp_hdr xid: 0x%x", dhcp_hdr->xid); - log_debug("dhcp_hdr secs: %u", dhcp_hdr->secs); - log_debug("dhcp_hdr flags: 0x%x", dhcp_hdr->flags); - log_debug("dhcp_hdr ciaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->ciaddr, - hbuf, sizeof(hbuf))); - log_debug("dhcp_hdr yiaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->yiaddr, - hbuf, sizeof(hbuf))); - log_debug("dhcp_hdr siaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->siaddr, - hbuf, sizeof(hbuf))); - log_debug("dhcp_hdr giaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->giaddr, - hbuf, sizeof(hbuf))); - log_debug("dhcp_hdr chaddr: %02x:%02x:%02x:%02x:%02x:%02x " - "(%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x)", - dhcp_hdr->chaddr[0], dhcp_hdr->chaddr[1], dhcp_hdr->chaddr[2], - dhcp_hdr->chaddr[3], dhcp_hdr->chaddr[4], dhcp_hdr->chaddr[5], - dhcp_hdr->chaddr[6], dhcp_hdr->chaddr[7], dhcp_hdr->chaddr[8], - dhcp_hdr->chaddr[9], dhcp_hdr->chaddr[10], dhcp_hdr->chaddr[11], - dhcp_hdr->chaddr[12], dhcp_hdr->chaddr[13], dhcp_hdr->chaddr[14], - dhcp_hdr->chaddr[15]); - /* ignore sname and file, if we ever print it use strvis(3) */ + + if (log_getverbose() > 1) + log_dhcp_hdr(dhcp_hdr); if (dhcp_hdr->op != DHCP_BOOTREPLY) { log_warnx("%s: ignorning non-reply packet", __func__); @@ -778,43 +763,20 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) switch(dho) { case DHO_PAD: - log_debug("DHO_PAD"); + if (log_getverbose() > 1) + log_debug("DHO_PAD"); break; case DHO_END: - log_debug("DHO_END"); + if (log_getverbose() > 1) + log_debug("DHO_END"); break; case DHO_DHCP_MESSAGE_TYPE: if (dho_len != 1) goto wrong_length; dhcp_message_type = *p; - switch (dhcp_message_type) { - case DHCPDISCOVER: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPDISCOVER"); - break; - case DHCPOFFER: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPOFFER"); - break; - case DHCPREQUEST: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPREQUEST"); - break; - case DHCPDECLINE: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPDECLINE"); - break; - case DHCPACK: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPACK"); - break; - case DHCPNAK: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPNAK"); - break; - case DHCPRELEASE: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPRELEASE"); - break; - case DHCPINFORM: - log_debug("DHO_DHCP_MESSAGE_TYPE: DHCPINFORM"); - break; - default: - log_debug("DHO_DHCP_MESSAGE_TYPE: Unknown"); - break; + if (log_getverbose() > 1) { + log_debug("DHO_DHCP_MESSAGE_TYPE: %s", + dhcp_message_type2str(dhcp_message_type)); } p += dho_len; rem -= dho_len; @@ -824,9 +786,11 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto wrong_length; memcpy(&server_identifier, p, sizeof(server_identifier)); - log_debug("DHO_DHCP_SERVER_IDENTIFIER: %s", - inet_ntop(AF_INET, &server_identifier, - hbuf, sizeof(hbuf))); + if (log_getverbose() > 1) { + log_debug("DHO_DHCP_SERVER_IDENTIFIER: %s", + inet_ntop(AF_INET, &server_identifier, + hbuf, sizeof(hbuf))); + } p += dho_len; rem -= dho_len; break; @@ -835,7 +799,10 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto wrong_length; memcpy(&lease_time, p, sizeof(lease_time)); lease_time = ntohl(lease_time); - log_debug("DHO_DHCP_LEASE_TIME %us", lease_time); + if (log_getverbose() > 1) { + log_debug("DHO_DHCP_LEASE_TIME %us", + lease_time); + } p += dho_len; rem -= dho_len; break; @@ -843,8 +810,11 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) if (dho_len != sizeof(subnet_mask)) goto wrong_length; memcpy(&subnet_mask, p, sizeof(subnet_mask)); - log_debug("DHO_SUBNET_MASK: %s", inet_ntop(AF_INET, - &subnet_mask, hbuf, sizeof(hbuf))); + if (log_getverbose() > 1) { + log_debug("DHO_SUBNET_MASK: %s", + inet_ntop(AF_INET, &subnet_mask, hbuf, + sizeof(hbuf))); + } p += dho_len; rem -= dho_len; break; @@ -855,9 +825,11 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto wrong_length; /* we only use one router */ memcpy(&router, p, sizeof(router)); - log_debug("DHO_ROUTER: %s (1/%lu)", inet_ntop(AF_INET, - &router, hbuf, sizeof(hbuf)), dho_len / - sizeof(router)); + if (log_getverbose() > 1) { + log_debug("DHO_ROUTER: %s (1/%lu)", + inet_ntop(AF_INET, &router, hbuf, + sizeof(hbuf)), dho_len / sizeof(router)); + } p += dho_len; rem -= dho_len; break; @@ -869,13 +841,15 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) /* we limit ourself to 8 nameservers for proposals */ memcpy(&nameservers, p, MINIMUM(sizeof(nameservers), dho_len)); - for (i = 0; i < MINIMUM(sizeof(nameservers), dho_len / - sizeof(nameservers[0])); - i++) { - log_debug("DHO_DOMAIN_NAME_SERVERS: %s " - "(%lu/%lu)", inet_ntop(AF_INET, - &nameservers[i], hbuf, sizeof(hbuf)), i + 1, - dho_len / sizeof(nameservers[0])); + if (log_getverbose() > 1) { + for (i = 0; i < MINIMUM(sizeof(nameservers), + dho_len / sizeof(nameservers[0])); i++) { + log_debug("DHO_DOMAIN_NAME_SERVERS: %s " + "(%lu/%lu)", inet_ntop(AF_INET, + &nameservers[i], hbuf, + sizeof(hbuf)), i + 1, + dho_len / sizeof(nameservers[0])); + } } p += dho_len; rem -= dho_len; @@ -883,8 +857,10 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) case DHO_DOMAIN_NAME: if ( dho_len < 1) goto wrong_length; - strvisx(vis_buf, p, dho_len, VIS_SAFE); - log_debug("DHO_DOMAIN_NAME: %s", vis_buf); + if (log_getverbose() > 1) { + strvisx(vis_buf, p, dho_len, VIS_SAFE); + log_debug("DHO_DOMAIN_NAME: %s", vis_buf); + } p += dho_len; rem -= dho_len; break; @@ -893,7 +869,10 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto wrong_length; memcpy(&renewal_time, p, sizeof(renewal_time)); renewal_time = ntohl(renewal_time); - log_debug("DHO_DHCP_RENEWAL_TIME %us", renewal_time); + if (log_getverbose() > 1) { + log_debug("DHO_DHCP_RENEWAL_TIME %us", + renewal_time); + } p += dho_len; rem -= dho_len; break; @@ -902,8 +881,10 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) goto wrong_length; memcpy(&rebinding_time, p, sizeof(rebinding_time)); rebinding_time = ntohl(rebinding_time); - log_debug("DHO_DHCP_REBINDING_TIME %us", - rebinding_time); + if (log_getverbose() > 1) { + log_debug("DHO_DHCP_REBINDING_TIME %us", + rebinding_time); + } p += dho_len; rem -= dho_len; break; @@ -925,7 +906,8 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) rem -= dho_len; break; default: - log_debug("DHO_%u, len: %u", dho, dho_len); + if (log_getverbose() > 1) + log_debug("DHO_%u, len: %u", dho, dho_len); p += dho_len; rem -= dho_len; } @@ -941,6 +923,11 @@ parse_dhcp(struct dhcpleased_iface *iface, struct imsg_dhcp *dhcp) log_warnx("%s: %lu bytes garbage data from %s", __func__, rem, from); + if_name = if_indextoname(iface->if_index, ifnamebuf); + log_debug("%s on %s from %s/%s to %s/%s", + dhcp_message_type2str(dhcp_message_type), if_name == NULL ? "?" : + if_name, from, hbuf_src, to, hbuf_dst); + switch (dhcp_message_type) { case DHCPOFFER: if (iface->state != IF_INIT) { @@ -1049,6 +1036,7 @@ state_transition(struct dhcpleased_iface *iface, enum if_state new_state) { enum if_state old_state = iface->state; struct timespec now, res; + char ifnamebuf[IF_NAMESIZE], *if_name; iface->state = new_state; switch (new_state) { @@ -1144,8 +1132,12 @@ state_transition(struct dhcpleased_iface *iface, enum if_state new_state) request_dhcp_request(iface); break; } - log_debug("%s %s -> %s, timo: %lld", __func__, if_state_name[old_state], - if_state_name[new_state], iface->timo.tv_sec); + + if_name = if_indextoname(iface->if_index, ifnamebuf); + log_debug("%s[%s] %s -> %s, timo: %lld", __func__, if_name == NULL ? + "?" : if_name, if_state_name[old_state], if_state_name[new_state], + iface->timo.tv_sec); + if (iface->timo.tv_sec == -1) { if (evtimer_pending(&iface->timer, NULL)) evtimer_del(&iface->timer); @@ -1238,12 +1230,9 @@ void log_lease(struct dhcpleased_iface *iface, int deconfigure) { char hbuf_lease[INET_ADDRSTRLEN], hbuf_server[INET_ADDRSTRLEN]; - char if_name[IF_NAMESIZE]; + char ifnamebuf[IF_NAMESIZE], *if_name; - memset(if_name, 0, sizeof(if_name)); - - if (if_indextoname(iface->if_index, if_name) == 0) - if_name[0] = '?'; + if_name = if_indextoname(iface->if_index, ifnamebuf); inet_ntop(AF_INET, &iface->requested_ip, hbuf_lease, sizeof(hbuf_lease)); inet_ntop(AF_INET, &iface->server_identifier, hbuf_server, @@ -1252,10 +1241,10 @@ log_lease(struct dhcpleased_iface *iface, int deconfigure) if (deconfigure) log_info("deleting %s from %s (lease from %s)", hbuf_lease, - if_name, hbuf_server); + if_name == NULL ? "?" : if_name, hbuf_server); else log_info("adding %s to %s (lease from %s)", hbuf_lease, - if_name, hbuf_server); + if_name == NULL ? "?" : if_name, hbuf_server); } void @@ -1301,12 +1290,9 @@ log_rdns(struct dhcpleased_iface *iface, int withdraw) { int i; char hbuf_rdns[INET_ADDRSTRLEN], hbuf_server[INET_ADDRSTRLEN]; - char if_name[IF_NAMESIZE], *rdns_buf = NULL, *tmp_buf; - - memset(if_name, 0, sizeof(if_name)); + char ifnamebuf[IF_NAMESIZE], *if_name, *rdns_buf = NULL, *tmp_buf; - if (if_indextoname(iface->if_index, if_name) == 0) - if_name[0] = '?'; + if_name = if_indextoname(iface->if_index, ifnamebuf); inet_ntop(AF_INET, &iface->server_identifier, hbuf_server, sizeof(hbuf_server)); @@ -1325,12 +1311,15 @@ log_rdns(struct dhcpleased_iface *iface, int withdraw) } if (rdns_buf != NULL) { - if (withdraw) + if (withdraw) { log_info("deleting nameservers%s (lease from %s on %s)", - rdns_buf, hbuf_server, if_name); - else + rdns_buf, hbuf_server, if_name == NULL ? "?" : + if_name); + } else { log_info("adding nameservers%s (lease from %s on %s)", - rdns_buf, hbuf_server, if_name); + rdns_buf, hbuf_server, if_name == NULL ? "?" : + if_name); + } free(rdns_buf); } } @@ -1390,3 +1379,62 @@ parse_lease(struct dhcpleased_iface *iface, struct imsg_ifinfo *imsg_ifinfo) if (inet_pton(AF_INET, p, &iface->requested_ip) != 1) iface->requested_ip.s_addr = INADDR_ANY; } + +void +log_dhcp_hdr(struct dhcp_hdr *dhcp_hdr) +{ + char hbuf[INET_ADDRSTRLEN]; + + log_debug("dhcp_hdr op: %s (%d)", dhcp_hdr->op == DHCP_BOOTREQUEST ? + "Boot Request" : dhcp_hdr->op == DHCP_BOOTREPLY ? "Boot Reply" : + "Unknown", dhcp_hdr->op); + log_debug("dhcp_hdr htype: %s (%d)", dhcp_hdr->htype == 1 ? "Ethernet": + "Unknown", dhcp_hdr->htype); + log_debug("dhcp_hdr hlen: %d", dhcp_hdr->hlen); + log_debug("dhcp_hdr hops: %d", dhcp_hdr->hops); + log_debug("dhcp_hdr xid: 0x%x", dhcp_hdr->xid); + log_debug("dhcp_hdr secs: %u", dhcp_hdr->secs); + log_debug("dhcp_hdr flags: 0x%x", dhcp_hdr->flags); + log_debug("dhcp_hdr ciaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->ciaddr, + hbuf, sizeof(hbuf))); + log_debug("dhcp_hdr yiaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->yiaddr, + hbuf, sizeof(hbuf))); + log_debug("dhcp_hdr siaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->siaddr, + hbuf, sizeof(hbuf))); + log_debug("dhcp_hdr giaddr: %s", inet_ntop(AF_INET, &dhcp_hdr->giaddr, + hbuf, sizeof(hbuf))); + log_debug("dhcp_hdr chaddr: %02x:%02x:%02x:%02x:%02x:%02x " + "(%02x%02x%02x%02x%02x%02x%02x%02x%02x%02x)", + dhcp_hdr->chaddr[0], dhcp_hdr->chaddr[1], dhcp_hdr->chaddr[2], + dhcp_hdr->chaddr[3], dhcp_hdr->chaddr[4], dhcp_hdr->chaddr[5], + dhcp_hdr->chaddr[6], dhcp_hdr->chaddr[7], dhcp_hdr->chaddr[8], + dhcp_hdr->chaddr[9], dhcp_hdr->chaddr[10], dhcp_hdr->chaddr[11], + dhcp_hdr->chaddr[12], dhcp_hdr->chaddr[13], dhcp_hdr->chaddr[14], + dhcp_hdr->chaddr[15]); + /* ignore sname and file, if we ever print it use strvis(3) */ +} + +const char * +dhcp_message_type2str(uint8_t dhcp_message_type) +{ + switch (dhcp_message_type) { + case DHCPDISCOVER: + return "DHCPDISCOVER"; + case DHCPOFFER: + return "DHCPOFFER"; + case DHCPREQUEST: + return "DHCPREQUEST"; + case DHCPDECLINE: + return "DHCPDECLINE"; + case DHCPACK: + return "DHCPACK"; + case DHCPNAK: + return "DHCPNAK"; + case DHCPRELEASE: + return "DHCPRELEASE"; + case DHCPINFORM: + return "DHCPINFORM"; + default: + return "Unknown"; + } +} diff --git a/sbin/dhcpleased/frontend.c b/sbin/dhcpleased/frontend.c index 0c5010fadf9..353082eca55 100644 --- a/sbin/dhcpleased/frontend.c +++ b/sbin/dhcpleased/frontend.c @@ -1,4 +1,4 @@ -/* $OpenBSD: frontend.c,v 1.2 2021/03/02 17:39:26 claudio Exp $ */ +/* $OpenBSD: frontend.c,v 1.3 2021/03/07 18:39:11 florian Exp $ */ /* * Copyright (c) 2017, 2021 Florian Obser @@ -624,8 +624,7 @@ handle_route_message(struct rt_msghdr *rtm, struct sockaddr **rti_info) { struct if_msghdr *ifm; int xflags, if_index; - char ifnamebuf[IFNAMSIZ]; - char *if_name; + char ifnamebuf[IF_NAMESIZE], *if_name; switch (rtm->rtm_type) { case RTM_IFINFO: @@ -653,7 +652,8 @@ handle_route_message(struct rt_msghdr *rtm, struct sockaddr **rti_info) case RTM_NEWADDR: ifm = (struct if_msghdr *)rtm; if_name = if_indextoname(ifm->ifm_index, ifnamebuf); - log_debug("RTM_NEWADDR: %s[%u]", if_name, ifm->ifm_index); + log_debug("RTM_NEWADDR: %s[%u]", if_name == NULL ? + "?" : if_name, ifm->ifm_index); update_iface(ifm->ifm_index, if_name); break; case RTM_PROPOSAL: @@ -699,13 +699,13 @@ bpf_receive(int fd, short events, void *arg) iface = (struct iface *)arg; - log_debug("%s: fd: %d", __func__, fd); if ((len = read(fd, iface->bpfev.buf, BPFLEN)) == -1) { log_warn("read"); return; } - /* XXX len = 0 */ - log_debug("%s: %ld", __func__, len); + + if (len == 0) + fatal("%s len == 0", __func__); memset(&imsg_dhcp, 0, sizeof(imsg_dhcp)); imsg_dhcp.if_index = iface->if_index; @@ -818,16 +818,19 @@ void send_discover(struct iface *iface) { ssize_t pkt_len; + char ifnamebuf[IF_NAMESIZE], *if_name; if (!event_initialized(&iface->bpfev.ev)) { iface->send_discover = 1; return; } iface->send_discover = 0; - log_debug("%s", __func__); + + if_name = if_indextoname(iface->if_index, ifnamebuf); + log_debug("DHCPDISCOVER on %s", if_name == NULL ? "?" : if_name); + pkt_len = build_packet(DHCPDISCOVER, iface->xid, &iface->hw_address, &iface->requested_ip, NULL); - log_debug("%s, pkt_len: %ld", __func__, pkt_len); bpf_send_packet(iface, dhcp_packet, pkt_len); } @@ -835,10 +838,13 @@ void send_request(struct iface *iface) { ssize_t pkt_len; + char ifnamebuf[IF_NAMESIZE], *if_name; + + if_name = if_indextoname(iface->if_index, ifnamebuf); + log_debug("DHCPREQUEST on %s", if_name == NULL ? "?" : if_name); pkt_len = build_packet(DHCPREQUEST, iface->xid, &iface->hw_address, &iface->requested_ip, &iface->server_identifier); - log_debug("%s, pkt_len: %ld", __func__, pkt_len); if (iface->dhcp_server.s_addr != INADDR_ANY) udp_send_packet(iface, dhcp_packet, pkt_len); else @@ -850,7 +856,6 @@ udp_send_packet(struct iface *iface, uint8_t *packet, ssize_t len) { struct sockaddr_in to; - log_debug("%s", __func__); memset(&to, 0, sizeof(to)); to.sin_family = AF_INET; to.sin_len = sizeof(to); @@ -960,8 +965,6 @@ set_bpfsock(int bpfsock, uint32_t if_index) { struct iface *iface; - log_debug("%s: %d fd: %d", __func__, if_index, bpfsock); - if ((iface = get_iface_by_id(if_index)) == NULL) { /* * The interface disappeared while we were waiting for the -- 2.20.1