More logging changes to stubby to correctly report profile, transport and stats for TCP and UDP when used as fallbacks.

Reporting UDP stats every 100 responses or timeouts to give user some indication UDP is being used.
This commit is contained in:
Sara Dickinson 2016-12-05 18:05:04 +00:00
parent 1ba2e5bf4d
commit 576e38977f
3 changed files with 30 additions and 8 deletions

View File

@ -716,17 +716,19 @@ _getdns_upstream_shutdown(getdns_upstream *upstream)
if (upstream->tls_auth_state > upstream->best_tls_auth_state)
upstream->best_tls_auth_state = upstream->tls_auth_state;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %s : Conn closed: Conn stats - Resp=%d,Timeouts=%d,Auth=%s,Keepalive(ms)=%d\n",
DEBUG_DAEMON("%s %s : Conn closed : Transport=%s - Resp=%d,Timeouts=%d,Auth=%s,Keepalive(ms)=%d\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "TCP"),
(int)upstream->responses_received, (int)upstream->responses_timeouts,
getdns_auth_str_array[upstream->tls_auth_state], (int)upstream->keepalive_timeout);
DEBUG_DAEMON("%s %s : Upstream stats - Resp=%d,Timeouts=%d,Transport=%s,Best_auth=%s\n",
DEBUG_DAEMON("%s %s : Upstream stats: Transport=%s - Resp=%d,Timeouts=%d,Best_auth=%s\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "TCP"),
(int)upstream->total_responses, (int)upstream->total_timeouts,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "UDP/TCP"),
getdns_auth_str_array[upstream->best_tls_auth_state]);
DEBUG_DAEMON("%s %s : Upstream stats - Conns=%d,Conn_fails=%d,Conn_shutdowns=%d,Backoffs=%d\n",
DEBUG_DAEMON("%s %s : Upstream stats: Transport=%s - Conns=%d,Conn_fails=%d,Conn_shutdowns=%d,Backoffs=%d\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "TCP"),
(int)upstream->conn_completed, (int)upstream->conn_setup_failed,
(int)upstream->conn_shutdowns, (int)upstream->conn_backoffs);
#endif
@ -903,6 +905,8 @@ upstream_init(getdns_upstream *upstream,
/* How is this upstream doing on UDP? */
upstream->to_retry = 2;
upstream->back_off = 1;
upstream->udp_responses = 0;
upstream->udp_timeouts = 0;
/* For sharing a socket to this upstream with TCP */
upstream->fd = -1;

View File

@ -131,6 +131,8 @@ typedef struct getdns_upstream {
/* How is this upstream doing over UDP? */
int to_retry;
int back_off;
size_t udp_responses;
size_t udp_timeouts;
/* For stateful upstreams, need to share the connection and track the
activity on the connection */

View File

@ -571,6 +571,13 @@ stub_timeout_cb(void *userarg)
/* Handle upstream*/
if (netreq->fd >= 0) {
close(netreq->fd);
netreq->upstream->udp_timeouts++;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
if (netreq->upstream->udp_timeouts % 100 == 0)
DEBUG_DAEMON("%s %s : Upstream stats: Transport=UDP - Resp=%d,Timeouts=%d\n",
STUB_DEBUG_DAEMON, netreq->upstream->addr_str,
(int)netreq->upstream->udp_responses, (int)netreq->upstream->udp_timeouts);
#endif
stub_next_upstream(netreq);
} else {
netreq->upstream->responses_timeouts++;
@ -1305,6 +1312,13 @@ stub_udp_read_cb(void *userarg)
dnsreq->upstreams->current_udp = 0;
netreq->debug_end_time = _getdns_get_time_as_uintt64();
netreq->state = NET_REQ_FINISHED;
upstream->udp_responses++;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
if (upstream->udp_responses % 100 == 0)
DEBUG_DAEMON("%s %s : Upstream stats: Transport=UDP - Resp=%d,Timeouts=%d\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(int)upstream->udp_responses, (int)upstream->udp_timeouts);
#endif
_getdns_check_dns_req_complete(dnsreq);
}
@ -1767,15 +1781,16 @@ upstream_connect(getdns_upstream *upstream, getdns_transport_list_t transport,
upstream->tls_hs_state = GETDNS_HS_WRITE;
}
upstream->conn_state = GETDNS_CONN_SETUP;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %s : Conn init : Transport= %s - Profile=%s\n", STUB_DEBUG_DAEMON,
upstream->addr_str, transport == GETDNS_TRANSPORT_TLS ? "TLS":"TCP",
dnsreq->context->tls_auth_min == GETDNS_AUTHENTICATION_NONE ? "Opportunistic":"Strict");
#endif
break;
default:
return -1;
/* Nothing to do*/
}
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %s : Conn init\n",
STUB_DEBUG_DAEMON, upstream->addr_str);
#endif
return fd;
}
@ -1841,6 +1856,7 @@ fallback_on_write(getdns_network_req *netreq)
/* Deal with UDP one day*/
DEBUG_STUB("%s %-35s: MSG: %p FALLING BACK \n", STUB_DEBUG_SCHEDULE, __FUNCTION__, netreq);
DEBUG_DAEMON("%s Falling back...\n", STUB_DEBUG_DAEMON);
/* Try to find a fallback transport*/
getdns_return_t result = _getdns_submit_stub_request(netreq);