diff --git a/configure.ac b/configure.ac index 43d653e3..bc07ab09 100644 --- a/configure.ac +++ b/configure.ac @@ -149,15 +149,16 @@ fi ]) ACX_ARG_RPATH - +AC_ARG_ENABLE(debug-req, AC_HELP_STRING([--enable-debug-req], [Enable request debugging])) AC_ARG_ENABLE(debug-sched, AC_HELP_STRING([--enable-debug-sched], [Enable scheduling debugging messages])) AC_ARG_ENABLE(debug-stub, AC_HELP_STRING([--enable-debug-stub], [Enable stub debugging messages])) AC_ARG_ENABLE(debug-daemon, AC_HELP_STRING([--enable-debug-daemon], [Enable daemon debugging messages])) AC_ARG_ENABLE(debug-sec, AC_HELP_STRING([--enable-debug-sec], [Enable dnssec debugging messages])) AC_ARG_ENABLE(debug-server, AC_HELP_STRING([--enable-debug-server], [Enable server debugging messages])) -AC_ARG_ENABLE(all-debugging, AC_HELP_STRING([--enable-all-debugging], [Enable scheduling, stub and dnssec debugging])) +AC_ARG_ENABLE(all-debugging, AC_HELP_STRING([--enable-all-debugging], [Enable all debugging messages])) case "$enable_all_debugging" in yes) + enable_debug_req=yes enable_debug_sched=yes enable_debug_stub=yes enable_debug_daemon=yes @@ -167,6 +168,13 @@ case "$enable_all_debugging" in no|*) ;; esac +case "$enable_debug_req" in + yes) + AC_DEFINE_UNQUOTED([REQ_DEBUG], [1], [Define this to enable printing of request debugging messages.]) + ;; + no|*) + ;; +esac case "$enable_debug_sched" in yes) AC_DEFINE_UNQUOTED([SCHED_DEBUG], [1], [Define this to enable printing of scheduling debugging messages.]) diff --git a/src/context.c b/src/context.c index 0748f40c..2af25a3f 100644 --- a/src/context.c +++ b/src/context.c @@ -691,7 +691,10 @@ _getdns_upstreams_dereference(getdns_upstreams *upstreams) while (upstream->finished_dnsreqs) { dnsreq = upstream->finished_dnsreqs; upstream->finished_dnsreqs = dnsreq->finished_next; - _getdns_context_cancel_request(dnsreq); + if (!dnsreq->internal_cb) { /* Not part of chain */ + debug_req("Destroy ", *dnsreq->netreqs); + _getdns_context_cancel_request(dnsreq); + } } if (upstream->tls_session != NULL) SSL_SESSION_free(upstream->tls_session); @@ -3080,13 +3083,17 @@ getdns_cancel_callback(getdns_context *context, getdns_context_request_count_changed(context); + debug_req("CB Cancel ", *dnsreq->netreqs); if (dnsreq->user_callback) { dnsreq->context->processing = 1; dnsreq->user_callback(dnsreq->context, GETDNS_CALLBACK_CANCEL, NULL, dnsreq->user_pointer, dnsreq->trans_id); dnsreq->context->processing = 0; } - _getdns_context_cancel_request(dnsreq); + if (!dnsreq->internal_cb) { /* Not part of chain */ + debug_req("Destroy ", *dnsreq->netreqs); + _getdns_context_cancel_request(dnsreq); + } return GETDNS_RETURN_GOOD; } /* getdns_cancel_callback */ @@ -3095,6 +3102,7 @@ _getdns_context_request_timed_out(getdns_dns_req *dnsreq) { DEBUG_SCHED("%s(%p)\n", __FUNC__, (void *)dnsreq); + debug_req("CB Timeout ", *dnsreq->netreqs); if (dnsreq->user_callback) { dnsreq->context->processing = 1; dnsreq->user_callback(dnsreq->context, GETDNS_CALLBACK_TIMEOUT, diff --git a/src/debug.h b/src/debug.h index 9c5fa6f1..fb74527c 100644 --- a/src/debug.h +++ b/src/debug.h @@ -36,7 +36,6 @@ #define DEBUG_H #include "config.h" - #define STUB_DEBUG_ENTRY "=> ENTRY: " #define STUB_DEBUG_SETUP "--- SETUP: " #define STUB_DEBUG_SETUP_TLS "--- SETUP(TLS): " @@ -91,6 +90,31 @@ #define DEBUG_OFF(...) do {} while (0) +#if defined(REQ_DEBUG) && REQ_DEBUG +#include +#define DEBUG_REQ(...) DEBUG_ON(__VA_ARGS__) +#include "gldns/wire2str.h" +#include "rr-dict.h" +#include "types-internal.h" +static inline void debug_req(const char *msg, getdns_network_req *netreq) +{ + char str[1024]; + struct timeval tv; + uint64_t t; + + (void) gettimeofday(&tv, NULL); + t = tv.tv_sec * 1000 + tv.tv_usec / 1000; + t = t >= netreq->owner->expires ? 0 : netreq->owner->expires - t; + (void) gldns_wire2str_dname_buf(netreq->owner->name, + netreq->owner->name_len, str, sizeof(str)); + DEBUG_REQ("NETREQ %s %4"PRIu64" %s %s\n", msg, t, + str, _getdns_rr_type_name(netreq->request_type)); +} +#else +#define DEBUG_REQ(...) DEBUG_OFF(__VA_ARGS__) +#define debug_req(...) DEBUG_OFF(__VA_ARGS__) +#endif + #if defined(SCHED_DEBUG) && SCHED_DEBUG #include #define DEBUG_SCHED(...) DEBUG_ON(__VA_ARGS__) @@ -139,7 +163,8 @@ #define DEBUG_MDNS(...) DEBUG_OFF(__VA_ARGS__) #endif -#if (defined(SCHED_DEBUG) && SCHED_DEBUG) || \ +#if (defined(REQ_DEBUG) && REQ_DEBUG) || \ + (defined(SCHED_DEBUG) && SCHED_DEBUG) || \ (defined(STUB_DEBUG) && STUB_DEBUG) || \ (defined(DAEMON_DEBUG) && DAEMON_DEBUG) || \ (defined(SEC_DEBUG) && SEC_DEBUG) || \ diff --git a/src/dnssec.c b/src/dnssec.c index b3e86bae..8c01a635 100644 --- a/src/dnssec.c +++ b/src/dnssec.c @@ -3113,6 +3113,43 @@ static void check_chain_complete(chain_head *chain) _getdns_call_user_callback(dnsreq, response_dict); } +void _getdns_validation_chain_timeout(getdns_dns_req *dnsreq) +{ + chain_head *head = dnsreq->chain, *next; + chain_node *node; + size_t node_count; + + while (head) { + next = head->next; + + for ( node_count = head->node_count, node = head->parent + ; node_count + ; node_count--, node = node->parent ) { + + if (!_getdns_netreq_finished(node->dnskey_req)) { + _getdns_context_cancel_request( + node->dnskey_req->owner); + node->dnskey_req = NULL; + } + + if (!_getdns_netreq_finished(node->ds_req)) { + _getdns_context_cancel_request( + node->ds_req->owner); + node->ds_req = NULL; + } + + if (!_getdns_netreq_finished(node->soa_req)) { + _getdns_context_cancel_request( + node->soa_req->owner); + node->soa_req = NULL; + } + } + head = next; + } + dnsreq->request_timed_out = 1; + check_chain_complete(dnsreq->chain); +} + void _getdns_cancel_validation_chain(getdns_dns_req *dnsreq) { chain_head *head = dnsreq->chain, *next; diff --git a/src/dnssec.h b/src/dnssec.h index b7becfe9..b0334d52 100644 --- a/src/dnssec.h +++ b/src/dnssec.h @@ -47,6 +47,7 @@ /* Do some additional requests to fetch the complete validation chain */ void _getdns_get_validation_chain(getdns_dns_req *dns_req); void _getdns_cancel_validation_chain(getdns_dns_req *dns_req); +void _getdns_validation_chain_timeout(getdns_dns_req *dns_req); uint16_t _getdns_parse_ta_file(time_t *ta_mtime, gldns_buffer *gbuf); diff --git a/src/general.c b/src/general.c index cc6e1fe9..280df08d 100644 --- a/src/general.c +++ b/src/general.c @@ -53,6 +53,7 @@ #include "stub.h" #include "dict.h" #include "mdns.h" +#include "debug.h" void _getdns_call_user_callback(getdns_dns_req *dnsreq, getdns_dict *response) { @@ -61,8 +62,9 @@ void _getdns_call_user_callback(getdns_dns_req *dnsreq, getdns_dict *response) if (dnsreq->user_callback) { dnsreq->context->processing = 1; dnsreq->user_callback(dnsreq->context, - (response ? GETDNS_CALLBACK_COMPLETE - : GETDNS_CALLBACK_ERROR), + ( ! response ? GETDNS_CALLBACK_ERROR + : dnsreq->request_timed_out ? GETDNS_CALLBACK_TIMEOUT + : GETDNS_CALLBACK_COMPLETE ), response, dnsreq->user_pointer, dnsreq->trans_id); dnsreq->context->processing = 0; } @@ -186,6 +188,14 @@ _getdns_check_dns_req_complete(getdns_dns_req *dns_req) return; } } +#if defined(REQ_DEBUG) && REQ_DEBUG + if (dns_req->internal_cb) + debug_req("CB Internal", *dns_req->netreqs); + else if (results_found) + debug_req("CB Complete", *dns_req->netreqs); + else + debug_req("CB Error ", *dns_req->netreqs); +#endif if (dns_req->internal_cb) { _getdns_context_clear_outbound_request(dns_req); dns_req->internal_cb(dns_req); @@ -206,9 +216,20 @@ _getdns_check_dns_req_complete(getdns_dns_req *dns_req) dns_req->dnssec_return_all_statuses )) #endif - )) + )) { + /* Reschedule timeout for this DNS request + */ + if (dns_req->timeout.timeout_cb && dns_req->timeout.ev) + GETDNS_CLEAR_EVENT(dns_req->loop, &dns_req->timeout); + + GETDNS_SCHEDULE_EVENT(dns_req->loop, -1, + _getdns_ms_until_expiry2(dns_req->expires, &now_ms), + getdns_eventloop_event_init(&dns_req->timeout, dns_req, + NULL, NULL, (getdns_eventloop_callback) + _getdns_validation_chain_timeout)); + _getdns_get_validation_chain(dns_req); - else + } else _getdns_call_user_callback( dns_req, _getdns_create_getdns_response(dns_req)); } @@ -373,6 +394,8 @@ _getdns_submit_netreq(getdns_network_req *netreq, uint64_t *now_ms) } _getdns_netreq_change_state(netreq, NET_REQ_IN_FLIGHT); + debug_req("Submitting ", netreq); + #ifdef STUB_NATIVE_DNSSEC # ifdef DNSSEC_ROADBLOCK_AVOIDANCE diff --git a/src/request-internal.c b/src/request-internal.c index 1bd5475e..d91563f4 100644 --- a/src/request-internal.c +++ b/src/request-internal.c @@ -944,6 +944,7 @@ _getdns_dns_req_new(getdns_context *context, getdns_eventloop *loop, result->freed = NULL; result->validating = 0; result->is_dns_request = 1; + result->request_timed_out = 0; result->chain = NULL; network_req_init(result->netreqs[0], result, diff --git a/src/stub.c b/src/stub.c index 30c08091..e8a8ee52 100644 --- a/src/stub.c +++ b/src/stub.c @@ -32,6 +32,12 @@ */ #include "config.h" + +/* Intercept and do not sent out COM DS queries with TLS + * For debugging purposes only. Never commit with this turned on. + */ +#define INTERCEPT_COM_DS 0 + #ifdef USE_POLL_DEFAULT_EVENTLOOP # ifdef HAVE_SYS_POLL_H # include @@ -1306,10 +1312,39 @@ stub_tls_write(getdns_upstream *upstream, getdns_tcp_state *tcp, /* TODO[TLS]: Handle error cases, partial writes, renegotiation etc. */ ERR_clear_error(); - written = SSL_write(tls_obj, netreq->query - 2, pkt_len + 2); - if (written <= 0) - return STUB_TCP_ERROR; +#if INTERCEPT_COM_DS + /* Intercept and do not sent out COM DS queries. For debugging + * purposes only. Never commit with this turned on. + */ + if (netreq->request_type == GETDNS_RRTYPE_DS && + netreq->owner->name_len == 5 && + netreq->owner->name[0] == 3 && + (netreq->owner->name[1] & 0xDF) == 'C' && + (netreq->owner->name[2] & 0xDF) == 'O' && + (netreq->owner->name[3] & 0xDF) == 'M' && + netreq->owner->name[4] == 0) { + debug_req("Intercepting", netreq); + written = pkt_len + 2; + } else +#endif + written = SSL_write(tls_obj, netreq->query - 2, pkt_len + 2); + if (written <= 0) { + /* SSL_write will not do partial writes, because + * SSL_MODE_ENABLE_PARTIAL_WRITE is not default, + * but the write could fail because of renegotiation. + * In that case SSL_get_error() will return + * SSL_ERROR_WANT_READ or, SSL_ERROR_WANT_WRITE. + * Return for retry in such cases. + */ + switch (SSL_get_error(tls_obj, written)) { + case SSL_ERROR_WANT_READ: + case SSL_ERROR_WANT_WRITE: + return STUB_TCP_AGAIN; + default: + return STUB_TCP_ERROR; + } + } /* We were able to write everything! Start reading. */ return (int) query_id; @@ -2080,6 +2115,12 @@ upstream_reschedule_events(getdns_upstream *upstream, uint64_t idle_timeout) { else { DEBUG_STUB("%s %-35s: FD: %d Connection idle - timeout is %d\n", STUB_DEBUG_SCHEDULE, __FUNC__, upstream->fd, (int)idle_timeout); + /* TODO: Schedule a read also anyway, + * to digest timed out answers. + * Dont forget to schedule with upstream->fd then! + * + * upstream->event.read_cb = upstream_read_cb; + */ upstream->event.timeout_cb = upstream_idle_timeout_cb; if (upstream->conn_state != GETDNS_CONN_OPEN) idle_timeout = 0; diff --git a/src/test/tpkg/070-coding-practice.tpkg/070-coding-practice.test b/src/test/tpkg/070-coding-practice.tpkg/070-coding-practice.test index b628a657..09473687 100644 --- a/src/test/tpkg/070-coding-practice.tpkg/070-coding-practice.test +++ b/src/test/tpkg/070-coding-practice.tpkg/070-coding-practice.test @@ -33,6 +33,19 @@ rm -f report.txt echo "" fi ) >> report.txt +( + cd ${SRCROOT}/src + if [ `grep '^#define[ ]*INTERCEPT_COM_DS[ ]*1' stub.c | wc -l` -gt 0 ] + then + echo "*** " + echo "*** The repo contained the COM DS queries interception" + echo "*** with TLS transports turned on, this should be off" + echo "*** " + grep -n '^#define[ ]INTERCEPT_COM_DS[ ]*1' stub.c + echo "" + fi +) >> report.txt + if [ -s report.txt ] then diff --git a/src/test/tpkg/225-stub-only-valgrind-checks.tpkg/225-stub-only-valgrind-checks.dsc b/src/test/tpkg/225-stub-only-valgrind-checks.tpkg/225-stub-only-valgrind-checks.dsc index d845ad44..7167a541 100644 --- a/src/test/tpkg/225-stub-only-valgrind-checks.tpkg/225-stub-only-valgrind-checks.dsc +++ b/src/test/tpkg/225-stub-only-valgrind-checks.tpkg/225-stub-only-valgrind-checks.dsc @@ -6,7 +6,7 @@ Maintainer: Willem Toorop Category: Component: CmdDepends: valgrind -Depends: 110-link.tpkg +Depends: 210-stub-only-link.tpkg Help: Pre: Post: diff --git a/src/types-internal.h b/src/types-internal.h index 5e1961ac..e70d8911 100644 --- a/src/types-internal.h +++ b/src/types-internal.h @@ -314,6 +314,7 @@ typedef struct getdns_dns_req { unsigned dnssec_ok_checking_disabled : 1; unsigned is_sync_request : 1; unsigned is_dns_request : 1; + unsigned request_timed_out : 1; /* The validating and freed variables are used to make sure a single * code path is followed while processing a DNS request, even when diff --git a/src/util-internal.c b/src/util-internal.c index 33c31745..ddac7b51 100644 --- a/src/util-internal.c +++ b/src/util-internal.c @@ -1263,6 +1263,7 @@ _getdns_create_getdns_response(getdns_dns_req *completed_request) GETDNS_FREE(context->mf, srvs.rrs); } if (getdns_dict_set_int(result, GETDNS_STR_KEY_STATUS, + completed_request->request_timed_out || nreplies == 0 ? GETDNS_RESPSTATUS_ALL_TIMEOUT : completed_request->dnssec_return_only_secure && nsecure == 0 && ninsecure > 0 ? GETDNS_RESPSTATUS_NO_SECURE_ANSWERS :