interesting
/
getdns
mirror of https://github.com/getdnsapi/getdns.git
1
0
Fork 0
Code Issues Projects Releases Wiki Activity

A configurable log function 

Currently used only for DAEMON_DEBUG
This commit is contained in:
Willem Toorop 2017-06-27 00:23:22 +02:00
parent ac084db231
commit 04e554086a
6 changed files with 148 additions and 55 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

73
src/context.c
View File

@ -61,6 +61,7 @@ typedef unsigned short in_port_t;
#include <assert.h>
#include <ctype.h>
#include <stdarg.h>
#ifdef HAVE_PTHREAD
#include <pthread.h>
@ -655,6 +656,7 @@ upstreams_create(getdns_context *context, size_t size)
r->current_stateful = 0;
r->tls_backoff_time = context->tls_backoff_time;
r->tls_connection_retries = context->tls_connection_retries;
r->log = context->log;
return r;
}
@ -719,6 +721,22 @@ _getdns_upstreams_dereference(getdns_upstreams *upstreams)
GETDNS_FREE(upstreams->mf, upstreams);
}
void _getdns_upstream_log(getdns_upstream *upstream, uint64_t system,
getdns_loglevel_type level, const char *fmt, ...)
{
va_list args;
if (!upstream || !upstream->upstreams || !upstream->upstreams->log.func
|| !(upstream->upstreams->log.system & system)
|| level > upstream->upstreams->log.level)
return;
va_start(args, fmt);
upstream->upstreams->log.func(
upstream->upstreams->log.userarg, system, level, fmt, args);
va_end(args);
}
void
_getdns_upstream_shutdown(getdns_upstream *upstream)
{
@ -732,23 +750,24 @@ _getdns_upstream_shutdown(getdns_upstream *upstream)
/* Keep track of the best auth state this upstream has had*/
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 %-40s : Conn closed : Transport=%s - Resp=%d,Timeouts=%d,Auth=%s,Keepalive(ms)=%d\n",
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : 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(upstream->tls_auth_state), (int)upstream->keepalive_timeout);
DEBUG_DAEMON("%s %-40s : Upstream stats: Transport=%s - Resp=%d,Timeouts=%d,Best_auth=%s\n",
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : 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,
_getdns_auth_str(upstream->best_tls_auth_state));
DEBUG_DAEMON("%s %-40s : Upstream stats: Transport=%s - Conns=%d,Conn_fails=%d,Conn_shutdowns=%d,Backoffs=%d\n",
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : 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
/* Back off connections that never got up service at all (probably no
TCP service or incompatible TLS version/cipher).
@ -771,11 +790,11 @@ _getdns_upstream_shutdown(getdns_upstream *upstream)
upstream->conn_setup_failed = 0;
upstream->conn_shutdowns = 0;
upstream->conn_backoffs++;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %-40s : !Backing off this upstream - Will retry as new upstream at %s",
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : !Backing off this upstream - Will retry as new upstream at %s",
STUB_DEBUG_DAEMON, upstream->addr_str,
asctime(gmtime(&upstream->conn_retry_time)));
#endif
}
// Reset per connection counters
upstream->queries_sent = 0;
@ -1366,6 +1385,11 @@ getdns_context_create_with_extended_memory_functions(
result->update_callback2 = NULL_update_callback;
result->update_userarg = NULL;
result->log.func = NULL;
result->log.userarg = NULL;
result->log.system = 0;
result->log.level = GETDNS_LOG_ERR;
result->mf.mf_arg = userarg;
result->mf.mf.ext.malloc = malloc;
result->mf.mf.ext.realloc = realloc;
@ -1681,7 +1705,7 @@ getdns_return_t
getdns_context_get_update_callback(getdns_context *context, void **userarg,
void (**cb)(getdns_context *, getdns_context_code_t, void *))
{
if (!context || !userarg || !cb)
if (!context || userarg || !cb)
return GETDNS_RETURN_INVALID_PARAMETER;
*userarg = context->update_userarg;
@ -1689,6 +1713,37 @@ getdns_context_get_update_callback(getdns_context *context, void **userarg,
return GETDNS_RETURN_GOOD;
}
getdns_return_t
getdns_context_set_logfunc(getdns_context *context, void *userarg,
uint64_t system, getdns_loglevel_type level, getdns_logfunc_type log)
{
if (!context)
return GETDNS_RETURN_INVALID_PARAMETER;
context->log.func = log;
context->log.userarg = userarg;
context->log.system = system;
context->log.level = level;
if (context->upstreams) {
context->upstreams->log = context->log;
}
return GETDNS_RETURN_GOOD;
}
void _getdns_context_log(getdns_context *context, uint64_t system,
getdns_loglevel_type level, const char *fmt, ...)
{
va_list args;
if (!context || !context->log.func || !(context->log.system & system)
|| level > context->log.level)
return;
va_start(args, fmt);
context->log.func(context->log.userarg, system, level, fmt, args);
va_end(args);
}
#ifdef HAVE_LIBUNBOUND
/*
* Helpers to set options on the unbound ctx

19
src/context.h
View File

@ -127,9 +127,7 @@ typedef struct getdns_upstream {
socklen_t addr_len;
struct sockaddr_storage addr;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
char addr_str[INET6_ADDRSTRLEN];
#endif
/**
* How is this upstream doing over UDP?
@ -238,6 +236,13 @@ typedef struct getdns_upstream {
} getdns_upstream;
typedef struct getdns_log_config {
getdns_logfunc_type func;
void *userarg;
uint64_t system;
getdns_loglevel_type level;
} getdns_log_config;
typedef struct getdns_upstreams {
struct mem_funcs mf;
size_t referenced;
@ -246,6 +251,7 @@ typedef struct getdns_upstreams {
size_t current_stateful;
uint16_t tls_backoff_time;
uint16_t tls_connection_retries;
getdns_log_config log;
getdns_upstream upstreams[];
} getdns_upstreams;
@ -296,6 +302,8 @@ struct getdns_context {
getdns_update_callback2 update_callback2;
void *update_userarg;
getdns_log_config log;
int processing;
int destroying;
@ -395,6 +403,13 @@ struct getdns_context {
#endif /* HAVE_MDNS_SUPPORT */
}; /* getdns_context */
void _getdns_upstream_log(getdns_upstream *upstream, uint64_t system,
getdns_loglevel_type level, const char *fmt, ...);
void _getdns_context_log(getdns_context *context, uint64_t system,
getdns_loglevel_type level, const char *fmt, ...);
/** internal functions **/
/**
* Sets up the unbound contexts with stub or recursive behavior

32
src/getdns/getdns_extra.h.in
View File

@ -39,6 +39,7 @@
#include <sys/time.h>
#include <stdio.h>
#include <time.h>
#include <stdarg.h>
#ifdef __cplusplus
extern "C" {
@ -501,13 +502,32 @@ getdns_context_set_tls_query_padding_blocksize(getdns_context *context, uint16_t
*/
getdns_return_t
getdns_context_unset_edns_maximum_udp_payload_size(getdns_context *context);
/** @}
*/
/**
* \addtogroup getdns_context
* @{
*/
typedef enum getdns_loglevel_type {
GETDNS_LOG_EMERG = 0,
GETDNS_LOG_ALERT = 1,
GETDNS_LOG_CRIT = 2,
GETDNS_LOG_ERR = 3,
GETDNS_LOG_WARNING = 4,
GETDNS_LOG_NOTICE = 5,
GETDNS_LOG_INFO = 6,
GETDNS_LOG_DEBUG = 7
} getdns_loglevel_type;
#define GETDNS_SYSTEM_DAEMON 0x100
#define GETDNS_SYSTEM_STUB 0x200
#define GETDNS_SYSTEM_MDNS 0x400
typedef void (*getdns_logfunc_type) (void *userarg, uint64_t system,
getdns_loglevel_type, const char *, va_list ap);
/**
*
*/
getdns_return_t
getdns_context_set_logfunc(getdns_context *context, void *userarg,
uint64_t system, getdns_loglevel_type level, getdns_logfunc_type func);
/**
* Get the current resolution type setting from this context.

1
src/libgetdns.symbols
View File

@ -55,6 +55,7 @@ getdns_context_set_follow_redirects
getdns_context_set_idle_timeout
getdns_context_set_limit_outstanding_queries
getdns_context_set_listen_addresses
getdns_context_set_logfunc
getdns_context_set_memory_functions
getdns_context_set_namespaces
getdns_context_set_resolution_type

67
src/stub.c
View File

@ -607,12 +607,11 @@ stub_timeout_cb(void *userarg)
close(netreq->fd);
#endif
netreq->upstream->udp_timeouts++;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
if (netreq->upstream->udp_timeouts % 100 == 0)
DEBUG_DAEMON("%s %-40s : Upstream stats: Transport=UDP - Resp=%d,Timeouts=%d\n",
_getdns_upstream_log(netreq->upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : 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++;
@ -908,12 +907,11 @@ tls_verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
STUB_DEBUG_SETUP_TLS, __FUNC__, upstream->fd, err,
X509_verify_cert_error_string(err));
#endif
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
if (!preverify_ok && !upstream->tls_fallback_ok)
DEBUG_DAEMON("%s %-40s : Verify failed : Transport=TLS - *Failure* - (%d) \"%s\"\n",
STUB_DEBUG_DAEMON, upstream->addr_str, err,
X509_verify_cert_error_string(err));
#endif
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Verify failed : Transport=TLS - *Failure* - (%d) \"%s\"\n",
STUB_DEBUG_DAEMON, upstream->addr_str, err,
X509_verify_cert_error_string(err));
/* First deal with the hostname authentication done by OpenSSL. */
#ifdef X509_V_ERR_HOSTNAME_MISMATCH
@ -945,11 +943,10 @@ tls_verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
if (upstream->tls_fallback_ok)
DEBUG_STUB("%s %-35s: FD: %d, WARNING: Proceeding even though pinset validation failed!\n",
STUB_DEBUG_SETUP_TLS, __FUNC__, upstream->fd);
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
else
DEBUG_DAEMON("%s %-40s : Conn failed : Transport=TLS - *Failure* - Pinset validation failure\n",
STUB_DEBUG_DAEMON, upstream->addr_str);
#endif
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Conn failed : Transport=TLS - *Failure* - Pinset validation failure\n",
STUB_DEBUG_DAEMON, upstream->addr_str);
} else {
/* If we _only_ had a pinset and it is good then force succesful
authentication when the cert self-signed
@ -960,10 +957,9 @@ tls_verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
preverify_ok = 1;
DEBUG_STUB("%s %-35s: FD: %d, Allowing self-signed (%d) cert since pins match\n",
STUB_DEBUG_SETUP_TLS, __FUNC__, upstream->fd, err);
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %-40s : Verify passed : Transport=TLS - Allowing self-signed cert since pins match\n",
STUB_DEBUG_DAEMON, upstream->addr_str);
#endif
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Verify passed : Transport=TLS - Allowing self-signed cert since pins match\n",
STUB_DEBUG_DAEMON, upstream->addr_str);
}
}
@ -1474,13 +1470,12 @@ stub_udp_read_cb(void *userarg)
netreq->debug_end_time = _getdns_get_time_as_uintt64();
_getdns_netreq_change_state(netreq, NET_REQ_FINISHED);
upstream->udp_responses++;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
if (upstream->udp_responses == 1 ||
upstream->udp_responses % 100 == 0)
DEBUG_DAEMON("%s %-40s : 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_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Upstream stats: Transport=UDP - Resp=%d,Timeouts=%d\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(int)upstream->udp_responses, (int)upstream->udp_timeouts);
_getdns_check_dns_req_complete(dnsreq);
}
@ -1734,11 +1729,10 @@ upstream_write_cb(void *userarg)
case STUB_NO_AUTH:
/* Cleaning up after connection or auth check failure. Need to fallback. */
stub_cleanup(netreq);
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %-40s : Conn closed : Transport=%s - *Failure*\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "TCP"));
#endif
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Conn closed : Transport=%s - *Failure*\n",
STUB_DEBUG_DAEMON, upstream->addr_str,
(upstream->transport == GETDNS_TRANSPORT_TLS ? "TLS" : "TCP"));
if (fallback_on_write(netreq) == STUB_TCP_ERROR) {
/* TODO: Need new state to report transport unavailable*/
_getdns_netreq_change_state(netreq, NET_REQ_ERRORED);
@ -1890,10 +1884,9 @@ upstream_select_stateful(getdns_network_req *netreq, getdns_transport_list_t tra
if (upstreams->upstreams[i].conn_state == GETDNS_CONN_BACKOFF &&
upstreams->upstreams[i].conn_retry_time < now) {
upstreams->upstreams[i].conn_state = GETDNS_CONN_CLOSED;
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s %-40s : Re-instating upstream\n",
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : Re-instating upstream\n",
STUB_DEBUG_DAEMON, upstreams->upstreams[i].addr_str);
#endif
}
}
@ -2024,11 +2017,10 @@ 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 %-40s : 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
_getdns_upstream_log(upstream, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s %-40s : 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");
break;
default:
return -1;
@ -2094,10 +2086,9 @@ upstream_find_for_netreq(getdns_network_req *netreq)
}
/* Handle better, will give generic error*/
DEBUG_STUB("%s %-35s: MSG: %p No valid upstream! \n", STUB_DEBUG_SCHEDULE, __FUNC__, (void*)netreq);
#if defined(DAEMON_DEBUG) && DAEMON_DEBUG
DEBUG_DAEMON("%s *FAILURE* no valid transports or upstreams available!\n",
STUB_DEBUG_DAEMON);
#endif
_getdns_context_log(netreq->owner->context, GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG,
"%s *FAILURE* no valid transports or upstreams available!\n",
STUB_DEBUG_DAEMON);
return -1;
}

11
src/tools/getdns_query.c
View File

@ -1619,6 +1619,14 @@ error:
getdns_dict_destroy(response);
}
static void stubby_log(void *userarg, uint64_t system,
getdns_loglevel_type level, const char *fmt, va_list ap)
{
(void)userarg; (void)system; (void)level;
(void) vfprintf(stderr, fmt, ap);
}
/**
* \brief A wrapper script for command line testing of getdns
* getdns_query -h provides details of the available options (the syntax is
@ -1668,6 +1676,9 @@ main(int argc, char **argv)
(void) parse_config_file(home_stubby_conf_fn, 0);
}
clear_listen_list_on_arg = 1;
(void) getdns_context_set_logfunc(context, NULL,
GETDNS_SYSTEM_DAEMON, GETDNS_LOG_DEBUG, stubby_log);
}
if ((r = parse_args(argc, argv)))
goto done_destroy_context;