From b1c795007fd6db4655a66ee2dfb306803a43fc1e Mon Sep 17 00:00:00 2001 From: Nick Mathewson Date: Fri, 23 Apr 2010 14:42:25 -0400 Subject: [PATCH] Make evdns logging threadsafe The old logging code was littered with places where we stored messages in static char[] fields. This is fine in a single-threaded program, but if you ever tried to log evdns messages from two threads at once, you'd hit a race. This patch also refactors evdns's debug_ntop function into a more useful evutil_sockaddr_port_format() function, with unit tests. --- evdns.c | 99 ++++++++++++++++++++------------------------- evutil.c | 29 +++++++++++++ test/regress_util.c | 38 +++++++++++++++++ util-internal.h | 8 ++++ 4 files changed, 119 insertions(+), 55 deletions(-) diff --git a/evdns.c b/evdns.c index 30269078..7b2b72cc 100644 --- a/evdns.c +++ b/evdns.c @@ -119,11 +119,6 @@ #define ASSERT_VALID_REQUEST(req) \ EVUTIL_ASSERT((req)->handle && (req)->handle->current_req == (req)) -#ifdef __USE_ISOC99B -/* libevent doesn't work without this */ -typedef unsigned int uint; -#endif - #define u64 ev_uint64_t #define u32 ev_uint32_t #define u16 ev_uint16_t @@ -415,38 +410,6 @@ static int strtoint(const char *const str); EVLOCK_ASSERT_LOCKED((base)->lock) #endif -static const char * -debug_ntoa(u32 address) -{ - static char buf[32]; - u32 a = ntohl(address); - evutil_snprintf(buf, sizeof(buf), "%d.%d.%d.%d", - (int)(u8)((a>>24)&0xff), - (int)(u8)((a>>16)&0xff), - (int)(u8)((a>>8 )&0xff), - (int)(u8)((a )&0xff)); - return buf; -} - -static const char * -debug_ntop(const struct sockaddr *sa) -{ - if (sa->sa_family == AF_INET) { - struct sockaddr_in *sin = (struct sockaddr_in *) sa; - return debug_ntoa(sin->sin_addr.s_addr); - } -#ifdef AF_INET6 - if (sa->sa_family == AF_INET6) { - static char buf[128]; - struct sockaddr_in6 *sin6 = (struct sockaddr_in6 *) sa; - const char *result; - result = evutil_inet_ntop(AF_INET6, &sin6->sin6_addr, buf, sizeof(buf)); - return result ? result : "unknown"; - } -#endif - return ""; -} - static void default_evdns_log_fn(int warning, const char *buf) { @@ -477,7 +440,7 @@ static void _evdns_log(int warn, const char *fmt, ...) { va_list args; - static char buf[512]; + char buf[512]; if (!evdns_log_fn) return; va_start(args,fmt); @@ -565,10 +528,12 @@ nameserver_probe_failed(struct nameserver *const ns) { ns->failed_times++; if (evtimer_add(&ns->timeout_event, &timeout) < 0) { - log(EVDNS_LOG_WARN, - "Error from libevent when adding timer event for %s", - debug_ntop((struct sockaddr *)&ns->address)); - /* ???? Do more? */ + char addrbuf[128]; + log(EVDNS_LOG_WARN, + "Error from libevent when adding timer event for %s", + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf))); } } @@ -579,6 +544,7 @@ nameserver_failed(struct nameserver *const ns, const char *msg) { struct request *req, *started_at; struct evdns_base *base = ns->base; int i; + char addrbuf[128]; ASSERT_LOCKED(base); /* if this nameserver has already been marked as failed */ @@ -586,7 +552,11 @@ nameserver_failed(struct nameserver *const ns, const char *msg) { if (!ns->state) return; log(EVDNS_LOG_MSG, "Nameserver %s has failed: %s", - debug_ntop((struct sockaddr*)&ns->address), msg); + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf)), + msg); + base->global_good_nameservers--; EVUTIL_ASSERT(base->global_good_nameservers >= 0); if (base->global_good_nameservers == 0) { @@ -600,7 +570,9 @@ nameserver_failed(struct nameserver *const ns, const char *msg) { &base->global_nameserver_probe_initial_timeout) < 0) { log(EVDNS_LOG_WARN, "Error from libevent when adding timer event for %s", - debug_ntop((struct sockaddr*)&ns->address)); + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf))); /* ???? Do more? */ } @@ -630,10 +602,13 @@ nameserver_failed(struct nameserver *const ns, const char *msg) { static void nameserver_up(struct nameserver *const ns) { + char addrbuf[128]; ASSERT_LOCKED(ns->base); if (ns->state) return; log(EVDNS_LOG_MSG, "Nameserver %s is back up", - debug_ntop((struct sockaddr *)&ns->address)); + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf))); evtimer_del(&ns->timeout_event); if (ns->probe_request) { evdns_cancel_request(ns->base, ns->probe_request); @@ -830,6 +805,7 @@ reply_schedule_callback(struct request *const req, u32 ttl, u32 err, struct repl static void reply_handle(struct request *const req, u16 flags, u32 ttl, struct reply *reply) { int error; + char addrbuf[128]; static const int error_codes[] = { DNS_ERR_FORMAT, DNS_ERR_SERVERFAILED, DNS_ERR_NOTEXIST, DNS_ERR_NOTIMPL, DNS_ERR_REFUSED @@ -869,9 +845,11 @@ reply_handle(struct request *const req, u16 flags, u32 ttl, struct reply *reply) * means "that request was very confusing." * Treat this as a timeout, not a failure. */ - log(EVDNS_LOG_DEBUG, "Got a SERVERFAILED from nameserver %s; " - "will allow the request to time out.", - debug_ntop((struct sockaddr *)&req->ns->address)); + log(EVDNS_LOG_DEBUG, "Got a SERVERFAILED from nameserver" + "at %s; will allow the request to time out.", + evutil_format_sockaddr_port( + (struct sockaddr *)&req->ns->address, + addrbuf, sizeof(addrbuf))); break; default: /* we got a good reply from the nameserver */ @@ -1287,6 +1265,7 @@ nameserver_read(struct nameserver *ns) { struct sockaddr_storage ss; ev_socklen_t addrlen = sizeof(ss); u8 packet[1500]; + char addrbuf[128]; ASSERT_LOCKED(ns->base); for (;;) { @@ -1304,7 +1283,9 @@ nameserver_read(struct nameserver *ns) { (struct sockaddr*)&ns->address, 0)) { log(EVDNS_LOG_WARN, "Address mismatch on received " "DNS packet. Apparent source was %s", - debug_ntop((struct sockaddr*)&ss)); + evutil_format_sockaddr_port( + (struct sockaddr *)&ss, + addrbuf, sizeof(addrbuf))); return; } @@ -1390,8 +1371,11 @@ nameserver_write_waiting(struct nameserver *ns, char waiting) { ns->socket, EV_READ | (waiting ? EV_WRITE : 0) | EV_PERSIST, nameserver_ready_callback, ns); if (event_add(&ns->event, NULL) < 0) { + char addrbuf[128]; log(EVDNS_LOG_WARN, "Error from libevent when adding event for %s", - debug_ntop((struct sockaddr *)&ns->address)); + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf))); /* ???? Do more? */ } } @@ -2195,12 +2179,15 @@ static void nameserver_send_probe(struct nameserver *const ns) { struct evdns_request *handle; struct request *req; + char addrbuf[128]; /* here we need to send a probe to a given nameserver */ /* in the hope that it is up now. */ ASSERT_LOCKED(ns->base); log(EVDNS_LOG_DEBUG, "Sending probe to %s", - debug_ntop((struct sockaddr *)&ns->address)); + evutil_format_sockaddr_port( + (struct sockaddr *)&ns->address, + addrbuf, sizeof(addrbuf))); handle = mm_calloc(1, sizeof(*handle)); if (!handle) return; req = request_new(ns->base, handle, TYPE_A, "google.com", DNS_QUERY_NO_SEARCH, nameserver_probe_callback, ns); @@ -2357,6 +2344,7 @@ _evdns_nameserver_add_impl(struct evdns_base *base, const struct sockaddr *addre const struct nameserver *server = base->server_head, *const started_at = base->server_head; struct nameserver *ns; int err = 0; + char addrbuf[128]; ASSERT_LOCKED(base); if (server) { @@ -2402,7 +2390,8 @@ _evdns_nameserver_add_impl(struct evdns_base *base, const struct sockaddr *addre goto out2; } - log(EVDNS_LOG_DEBUG, "Added nameserver %s", debug_ntop(address)); + log(EVDNS_LOG_DEBUG, "Added nameserver %s", + evutil_format_sockaddr_port(address, addrbuf, sizeof(addrbuf))); /* insert this nameserver into the list of them */ if (!base->server_head) { @@ -2426,14 +2415,14 @@ out2: out1: event_debug_unassign(&ns->event); mm_free(ns); - log(EVDNS_LOG_WARN, "Unable to add nameserver %s: error %d", debug_ntop(address), err); + log(EVDNS_LOG_WARN, "Unable to add nameserver %s: error %d", + evutil_format_sockaddr_port(address, addrbuf, sizeof(addrbuf)), err); return err; } /* exported function */ int -evdns_base_nameserver_add(struct evdns_base *base, - unsigned long int address) +evdns_base_nameserver_add(struct evdns_base *base, unsigned long int address) { struct sockaddr_in sin; int res; diff --git a/evutil.c b/evutil.c index 2509f175..a9d4ab5c 100644 --- a/evutil.c +++ b/evutil.c @@ -1726,6 +1726,35 @@ evutil_parse_sockaddr_port(const char *ip_as_string, struct sockaddr *out, int * } } +const char * +evutil_format_sockaddr_port(const struct sockaddr *sa, char *out, size_t outlen) +{ + char b[128]; + const char *res=NULL; + int port; + if (sa->sa_family == AF_INET) { + const struct sockaddr_in *sin = (const struct sockaddr_in*)sa; + res = evutil_inet_ntop(AF_INET, &sin->sin_addr,b,sizeof(b)); + port = ntohs(sin->sin_port); + if (res) { + evutil_snprintf(out, outlen, "%s:%d", b, port); + return out; + } + } else if (sa->sa_family == AF_INET6) { + const struct sockaddr_in6 *sin6 = (const struct sockaddr_in6*)sa; + res = evutil_inet_ntop(AF_INET6, &sin6->sin6_addr,b,sizeof(b)); + port = ntohs(sin6->sin6_port); + if (res) { + evutil_snprintf(out, outlen, "[%s]:%d", b, port); + return out; + } + } + + evutil_snprintf(out, outlen, "", + (int)sa->sa_family); + return out; +} + int evutil_sockaddr_cmp(const struct sockaddr *sa1, const struct sockaddr *sa2, int include_port) diff --git a/test/regress_util.c b/test/regress_util.c index 9b30d564..2e0d7722 100644 --- a/test/regress_util.c +++ b/test/regress_util.c @@ -276,6 +276,43 @@ regress_sockaddr_port_parse(void *ptr) } } + +static void +regress_sockaddr_port_format(void *ptr) +{ + struct sockaddr_storage ss; + int len; + const char *cp; + char cbuf[128]; + int r; + + len = sizeof(ss); + r = evutil_parse_sockaddr_port("192.168.1.1:80", + (struct sockaddr*)&ss, &len); + tt_int_op(r,==,0); + cp = evutil_format_sockaddr_port( + (struct sockaddr*)&ss, cbuf, sizeof(cbuf)); + tt_ptr_op(cp,==,cbuf); + tt_str_op(cp,==,"192.168.1.1:80"); + + len = sizeof(ss); + r = evutil_parse_sockaddr_port("[ff00::8010]:999", + (struct sockaddr*)&ss, &len); + tt_int_op(r,==,0); + cp = evutil_format_sockaddr_port( + (struct sockaddr*)&ss, cbuf, sizeof(cbuf)); + tt_ptr_op(cp,==,cbuf); + tt_str_op(cp,==,"[ff00::8010]:999"); + + ss.ss_family=99; + cp = evutil_format_sockaddr_port( + (struct sockaddr*)&ss, cbuf, sizeof(cbuf)); + tt_ptr_op(cp,==,cbuf); + tt_str_op(cp,==,""); +end: + ; +} + static struct sa_pred_ent { const char *parse; @@ -951,6 +988,7 @@ struct testcase_t util_testcases[] = { { "ipv4_parse", regress_ipv4_parse, 0, NULL, NULL }, { "ipv6_parse", regress_ipv6_parse, 0, NULL, NULL }, { "sockaddr_port_parse", regress_sockaddr_port_parse, 0, NULL, NULL }, + { "sockaddr_port_format", regress_sockaddr_port_format, 0, NULL, NULL }, { "sockaddr_predicates", test_evutil_sockaddr_predicates, 0,NULL,NULL }, { "evutil_snprintf", test_evutil_snprintf, 0, NULL, NULL }, { "evutil_strtoll", test_evutil_strtoll, 0, NULL, NULL }, diff --git a/util-internal.h b/util-internal.h index f5fff192..60d4dfee 100644 --- a/util-internal.h +++ b/util-internal.h @@ -213,6 +213,14 @@ int evutil_getaddrinfo_async(struct evdns_base *dns_base, * ::1). */ int evutil_sockaddr_is_loopback(const struct sockaddr *sa); + +/** + Formats a sockaddr sa into a string buffer of size outlen stored in out. + Returns a pointer to out. Always writes something into out, so it's safe + to use the output of this function without checking it for NULL. + */ +const char *evutil_format_sockaddr_port(const struct sockaddr *sa, char *out, size_t outlen); + long evutil_tv_to_msec(const struct timeval *tv); #ifdef __cplusplus