Minor tweaks

This commit is contained in:
Sara Dickinson 2016-03-18 12:02:40 +00:00
parent c08371ebb0
commit c1f15fc0ac
4 changed files with 61 additions and 59 deletions

View File

@ -152,7 +152,7 @@ add_WIN_cacerts_to_openssl_store(SSL_CTX* tls_ctx)
HCERTSTORE hSystemStore; HCERTSTORE hSystemStore;
PCCERT_CONTEXT pTargetCert = NULL; PCCERT_CONTEXT pTargetCert = NULL;
DEBUG_STUB("%s %-30s: %s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__, DEBUG_STUB("%s %-35s: %s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__,
"Adding Windows certificates to CA store"); "Adding Windows certificates to CA store");
/* load just once per context lifetime for this version of getdns /* load just once per context lifetime for this version of getdns
@ -181,7 +181,7 @@ add_WIN_cacerts_to_openssl_store(SSL_CTX* tls_ctx)
/* failure if the CA store is empty or the call fails */ /* failure if the CA store is empty or the call fails */
if ((pTargetCert = CertEnumCertificatesInStore( if ((pTargetCert = CertEnumCertificatesInStore(
hSystemStore, pTargetCert)) == 0) { hSystemStore, pTargetCert)) == 0) {
DEBUG_STUB("%s %-30s: %s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__, DEBUG_STUB("%s %-35s: %s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__,
"CA certificate store for Windows is empty."); "CA certificate store for Windows is empty.");
return 0; return 0;
} }
@ -193,7 +193,7 @@ add_WIN_cacerts_to_openssl_store(SSL_CTX* tls_ctx)
pTargetCert->cbCertEncoded); pTargetCert->cbCertEncoded);
if (!cert1) { if (!cert1) {
/* return error if a cert fails */ /* return error if a cert fails */
DEBUG_STUB("%s %-30s: %s %d:%s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__, DEBUG_STUB("%s %-35s: %s %d:%s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__,
"Unable to parse certificate in memory", "Unable to parse certificate in memory",
ERR_get_error(), ERR_error_string(ERR_get_error(), NULL)); ERR_get_error(), ERR_error_string(ERR_get_error(), NULL));
return 0; return 0;
@ -201,7 +201,7 @@ add_WIN_cacerts_to_openssl_store(SSL_CTX* tls_ctx)
else { else {
/* return error if a cert add to store fails */ /* return error if a cert add to store fails */
if (X509_STORE_add_cert(store, cert1) == 0) { if (X509_STORE_add_cert(store, cert1) == 0) {
DEBUG_STUB("%s %-30s: %s %d:%s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__, DEBUG_STUB("%s %-35s: %s %d:%s\n", STUB_DEBUG_SETUP_TLS, __FUNCTION__,
"Error adding certificate", ERR_get_error(), "Error adding certificate", ERR_get_error(),
ERR_error_string(ERR_get_error(), NULL)); ERR_error_string(ERR_get_error(), NULL));
return 0; return 0;

View File

@ -404,7 +404,7 @@ _getdns_verify_pinset_match(const sha256_pin_t *pinset,
if (x->cert_info == NULL) if (x->cert_info == NULL)
continue; continue;
#if defined(STUB_DEBUG) && STUB_DEBUG #if defined(STUB_DEBUG) && STUB_DEBUG
DEBUG_STUB("%s %-30s: Name of cert: %d ", DEBUG_STUB("%s %-35s: Name of cert: %d ",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, i); STUB_DEBUG_SETUP_TLS, __FUNCTION__, i);
if (x->cert_info->subject != NULL) if (x->cert_info->subject != NULL)
X509_NAME_print_ex_fp(stderr, x->cert_info->subject, 1, XN_FLAG_ONELINE); X509_NAME_print_ex_fp(stderr, x->cert_info->subject, 1, XN_FLAG_ONELINE);
@ -416,13 +416,13 @@ _getdns_verify_pinset_match(const sha256_pin_t *pinset,
/* digest the cert with sha256 */ /* digest the cert with sha256 */
len = i2d_X509_PUBKEY(X509_get_X509_PUBKEY(x), NULL); len = i2d_X509_PUBKEY(X509_get_X509_PUBKEY(x), NULL);
if (len > sizeof(raw)) { if (len > sizeof(raw)) {
DEBUG_STUB("%s %-30s: Pubkey %d is larger than "PRIsz" octets\n", DEBUG_STUB("%s %-35s: Pubkey %d is larger than "PRIsz" octets\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, sizeof(raw)); STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, sizeof(raw));
continue; continue;
} }
i2d_X509_PUBKEY(X509_get_X509_PUBKEY(x), &next); i2d_X509_PUBKEY(X509_get_X509_PUBKEY(x), &next);
if (next - raw != len) { if (next - raw != len) {
DEBUG_STUB("%s %-30s: Pubkey %d claimed it needed %d octets, really needed "PRIsz"\n", DEBUG_STUB("%s %-35s: Pubkey %d claimed it needed %d octets, really needed "PRIsz"\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, len, next - raw); STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, len, next - raw);
continue; continue;
} }
@ -431,11 +431,11 @@ _getdns_verify_pinset_match(const sha256_pin_t *pinset,
/* compare it */ /* compare it */
for (p = pinset; p; p = p->next) for (p = pinset; p; p = p->next)
if (0 == memcmp(buf, p->pin, sizeof(p->pin))) { if (0 == memcmp(buf, p->pin, sizeof(p->pin))) {
DEBUG_STUB("%s %-30s: Pubkey %d matched pin %p ("PRIsz")\n", DEBUG_STUB("%s %-35s: Pubkey %d matched pin %p ("PRIsz")\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, p, sizeof(p->pin)); STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, p, sizeof(p->pin));
return GETDNS_RETURN_GOOD; return GETDNS_RETURN_GOOD;
} else } else
DEBUG_STUB("%s %-30s: Pubkey %d did not match pin %p\n", DEBUG_STUB("%s %-35s: Pubkey %d did not match pin %p\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, p); STUB_DEBUG_SETUP_TLS, __FUNCTION__, i, p);
} }

View File

@ -461,7 +461,7 @@ _getdns_network_validate_tsig(getdns_network_req *req)
const EVP_MD *digester; const EVP_MD *digester;
HMAC_CTX ctx; HMAC_CTX ctx;
DEBUG_STUB("%s %-30s: Validate TSIG\n", STUB_DEBUG_TSIG, __FUNCTION__); DEBUG_STUB("%s %-35s: Validate TSIG\n", STUB_DEBUG_TSIG, __FUNCTION__);
for ( rr = _getdns_rr_iter_init(&rr_spc, req->query, for ( rr = _getdns_rr_iter_init(&rr_spc, req->query,
(req->response - req->query)) (req->response - req->query))
; rr ; rr
@ -477,7 +477,7 @@ _getdns_network_validate_tsig(getdns_network_req *req)
request_mac_len = gldns_read_uint16(rdf->pos); request_mac_len = gldns_read_uint16(rdf->pos);
if (request_mac_len != rdf->nxt - rdf->pos - 2) if (request_mac_len != rdf->nxt - rdf->pos - 2)
return; return;
DEBUG_STUB("%s %-30s: Request MAC found length %d\n", DEBUG_STUB("%s %-35s: Request MAC found length %d\n",
STUB_DEBUG_TSIG, __FUNCTION__, (int)(request_mac_len)); STUB_DEBUG_TSIG, __FUNCTION__, (int)(request_mac_len));
request_mac = rdf->pos + 2; request_mac = rdf->pos + 2;
@ -534,7 +534,7 @@ _getdns_network_validate_tsig(getdns_network_req *req)
response_mac_len = gldns_read_uint16(rdf->pos); response_mac_len = gldns_read_uint16(rdf->pos);
if (response_mac_len != rdf->nxt - rdf->pos - 2) if (response_mac_len != rdf->nxt - rdf->pos - 2)
return; return;
DEBUG_STUB("%s %-30s: Response MAC found length: %d\n", DEBUG_STUB("%s %-35s: Response MAC found length: %d\n",
STUB_DEBUG_TSIG, __FUNCTION__, (int)(response_mac_len)); STUB_DEBUG_TSIG, __FUNCTION__, (int)(response_mac_len));
response_mac = rdf->pos + 2; response_mac = rdf->pos + 2;
@ -559,7 +559,7 @@ _getdns_network_validate_tsig(getdns_network_req *req)
gldns_buffer_write(&gbuf, rdf->pos, other_len); gldns_buffer_write(&gbuf, rdf->pos, other_len);
/* TSIG found */ /* TSIG found */
DEBUG_STUB("%s %-30s: TSIG found, original ID: %d\n", DEBUG_STUB("%s %-35s: TSIG found, original ID: %d\n",
STUB_DEBUG_TSIG, __FUNCTION__, (int)original_id); STUB_DEBUG_TSIG, __FUNCTION__, (int)original_id);
gldns_write_uint16(req->response + 10, gldns_write_uint16(req->response + 10,
@ -596,7 +596,7 @@ _getdns_network_validate_tsig(getdns_network_req *req)
(void) HMAC_Update(&ctx, tsig_vars, gldns_buffer_position(&gbuf)); (void) HMAC_Update(&ctx, tsig_vars, gldns_buffer_position(&gbuf));
HMAC_Final(&ctx, result_mac, &result_mac_len); HMAC_Final(&ctx, result_mac, &result_mac_len);
DEBUG_STUB("%s %-30s: Result MAC length: %d\n", DEBUG_STUB("%s %-35s: Result MAC length: %d\n",
STUB_DEBUG_TSIG, __FUNCTION__, (int)(result_mac_len)); STUB_DEBUG_TSIG, __FUNCTION__, (int)(result_mac_len));
if (result_mac_len == response_mac_len && if (result_mac_len == response_mac_len &&
memcmp(result_mac, response_mac, result_mac_len) == 0) memcmp(result_mac, response_mac, result_mac_len) == 0)

View File

@ -246,7 +246,7 @@ match_edns_opt_rr(uint16_t code, uint8_t *response, size_t response_len,
size_t data_len = rr_iter->nxt - rr_iter->pos; size_t data_len = rr_iter->nxt - rr_iter->pos;
(void) gldns_wire2str_rr_scan( (void) gldns_wire2str_rr_scan(
&data, &data_len, &str, &str_len, (uint8_t *)rr_iter->pkt, rr_iter->pkt_end - rr_iter->pkt); &data, &data_len, &str, &str_len, (uint8_t *)rr_iter->pkt, rr_iter->pkt_end - rr_iter->pkt);
DEBUG_STUB("%s %-30s: OPT RR: %s\n", DEBUG_STUB("%s %-35s: OPT RR: %s\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, str_spc); STUB_DEBUG_CLEANUP, __FUNCTION__, str_spc);
#endif #endif
@ -336,7 +336,7 @@ process_keepalive(
upstream->keepalive_timeout = netreq->owner->context->idle_timeout; upstream->keepalive_timeout = netreq->owner->context->idle_timeout;
else { else {
upstream->keepalive_timeout = server_keepalive; upstream->keepalive_timeout = server_keepalive;
DEBUG_STUB("%s %-30s: FD: %d Server Keepalive used: %d ms\n", DEBUG_STUB("%s %-35s: FD: %d Server Keepalive used: %d ms\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd, STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd,
(int)server_keepalive); (int)server_keepalive);
} }
@ -367,7 +367,7 @@ static int
tcp_connect(getdns_upstream *upstream, getdns_transport_list_t transport) tcp_connect(getdns_upstream *upstream, getdns_transport_list_t transport)
{ {
int fd = -1; int fd = -1;
DEBUG_STUB("%s %-30s: Creating TCP connection: %p\n", STUB_DEBUG_SETUP, DEBUG_STUB("%s %-35s: Creating TCP connection: %p\n", STUB_DEBUG_SETUP,
__FUNCTION__, upstream); __FUNCTION__, upstream);
if ((fd = socket(upstream->addr.ss_family, SOCK_STREAM, IPPROTO_TCP)) == -1) if ((fd = socket(upstream->addr.ss_family, SOCK_STREAM, IPPROTO_TCP)) == -1)
return -1; return -1;
@ -455,7 +455,7 @@ stub_next_upstream(getdns_network_req *netreq)
static void static void
stub_cleanup(getdns_network_req *netreq) stub_cleanup(getdns_network_req *netreq)
{ {
DEBUG_STUB("%s %-30s: MSG: %p\n", DEBUG_STUB("%s %-35s: MSG: %p\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, netreq); STUB_DEBUG_CLEANUP, __FUNCTION__, netreq);
getdns_dns_req *dnsreq = netreq->owner; getdns_dns_req *dnsreq = netreq->owner;
getdns_network_req *r, *prev_r; getdns_network_req *r, *prev_r;
@ -497,7 +497,7 @@ stub_cleanup(getdns_network_req *netreq)
static int static int
tls_cleanup(getdns_upstream *upstream) tls_cleanup(getdns_upstream *upstream)
{ {
DEBUG_STUB("%s %-30s: FD: %d\n", DEBUG_STUB("%s %-35s: FD: %d\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd); STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd);
if (upstream->tls_obj != NULL) if (upstream->tls_obj != NULL)
SSL_free(upstream->tls_obj); SSL_free(upstream->tls_obj);
@ -564,7 +564,7 @@ static void
stub_timeout_cb(void *userarg) stub_timeout_cb(void *userarg)
{ {
getdns_network_req *netreq = (getdns_network_req *)userarg; getdns_network_req *netreq = (getdns_network_req *)userarg;
DEBUG_STUB("%s %-30s: MSG: %p\n", DEBUG_STUB("%s %-35s: MSG: %p\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, netreq); STUB_DEBUG_CLEANUP, __FUNCTION__, netreq);
stub_next_upstream(netreq); stub_next_upstream(netreq);
stub_cleanup(netreq); stub_cleanup(netreq);
@ -582,7 +582,7 @@ static void
upstream_idle_timeout_cb(void *userarg) upstream_idle_timeout_cb(void *userarg)
{ {
getdns_upstream *upstream = (getdns_upstream *)userarg; getdns_upstream *upstream = (getdns_upstream *)userarg;
DEBUG_STUB("%s %-30s: FD: %d Closing connection\n", DEBUG_STUB("%s %-35s: FD: %d Closing connection\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd); STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd);
GETDNS_CLEAR_EVENT(upstream->loop, &upstream->event); GETDNS_CLEAR_EVENT(upstream->loop, &upstream->event);
upstream->event.timeout_cb = NULL; upstream->event.timeout_cb = NULL;
@ -595,7 +595,7 @@ static void
upstream_tls_timeout_cb(void *userarg) upstream_tls_timeout_cb(void *userarg)
{ {
getdns_upstream *upstream = (getdns_upstream *)userarg; getdns_upstream *upstream = (getdns_upstream *)userarg;
DEBUG_STUB("%s %-30s: FD: %d\n", DEBUG_STUB("%s %-35s: FD: %d\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd); STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd);
/* Clean up and trigger a write to let the fallback code to its job */ /* Clean up and trigger a write to let the fallback code to its job */
tls_cleanup(upstream); tls_cleanup(upstream);
@ -623,7 +623,7 @@ stub_tls_timeout_cb(void *userarg)
{ {
getdns_network_req *netreq = (getdns_network_req *)userarg; getdns_network_req *netreq = (getdns_network_req *)userarg;
getdns_upstream *upstream = netreq->upstream; getdns_upstream *upstream = netreq->upstream;
DEBUG_STUB("%s %-30s: MSG: %p\n", DEBUG_STUB("%s %-35s: MSG: %p\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, netreq); STUB_DEBUG_CLEANUP, __FUNCTION__, netreq);
/* Clean up and trigger a write to let the fallback code to its job */ /* Clean up and trigger a write to let the fallback code to its job */
tls_cleanup(upstream); tls_cleanup(upstream);
@ -758,7 +758,7 @@ stub_tcp_write(int fd, getdns_tcp_state *tcp, getdns_network_req *netreq)
if (netreq->upstream->writes_done == 0 && if (netreq->upstream->writes_done == 0 &&
netreq->owner->context->idle_timeout != 0) { netreq->owner->context->idle_timeout != 0) {
/* Add the keepalive option to the first query on this connection*/ /* Add the keepalive option to the first query on this connection*/
DEBUG_STUB("%s %-30s: FD: %d Requesting keepalive \n", DEBUG_STUB("%s %-35s: FD: %d Requesting keepalive \n",
STUB_DEBUG_WRITE, __FUNCTION__, fd); STUB_DEBUG_WRITE, __FUNCTION__, fd);
if (attach_edns_keepalive(netreq)) if (attach_edns_keepalive(netreq))
return STUB_OUT_OF_OPTIONS; return STUB_OUT_OF_OPTIONS;
@ -884,7 +884,7 @@ tls_verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
#if defined(STUB_DEBUG) && STUB_DEBUG || defined(X509_V_ERR_HOSTNAME_MISMATCH) #if defined(STUB_DEBUG) && STUB_DEBUG || defined(X509_V_ERR_HOSTNAME_MISMATCH)
int err = X509_STORE_CTX_get_error(ctx); int err = X509_STORE_CTX_get_error(ctx);
DEBUG_STUB("%s %-30s: FD: %d Verify result: (%d) \"%s\"\n", DEBUG_STUB("%s %-35s: FD: %d Verify result: (%d) \"%s\"\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd, err, STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd, err,
X509_verify_cert_error_string(err)); X509_verify_cert_error_string(err));
#endif #endif
@ -892,19 +892,19 @@ tls_verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
#ifdef X509_V_ERR_HOSTNAME_MISMATCH #ifdef X509_V_ERR_HOSTNAME_MISMATCH
/*Report if error is hostname mismatch*/ /*Report if error is hostname mismatch*/
if (upstream && upstream->tls_fallback_ok && err == X509_V_ERR_HOSTNAME_MISMATCH) if (upstream && upstream->tls_fallback_ok && err == X509_V_ERR_HOSTNAME_MISMATCH)
DEBUG_STUB("%s %-30s: FD: %d WARNING: Proceeding even though hostname validation failed!\n", DEBUG_STUB("%s %-35s: FD: %d WARNING: Proceeding even though hostname validation failed!\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd); STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd);
#endif #endif
if (upstream && upstream->tls_pubkey_pinset) if (upstream && upstream->tls_pubkey_pinset)
pinset_ret = _getdns_verify_pinset_match(upstream->tls_pubkey_pinset, ctx); pinset_ret = _getdns_verify_pinset_match(upstream->tls_pubkey_pinset, ctx);
if (pinset_ret != GETDNS_RETURN_GOOD) { if (pinset_ret != GETDNS_RETURN_GOOD) {
DEBUG_STUB("%s %-30s: FD: %d, WARNING: Pinset validation failure!\n", DEBUG_STUB("%s %-35s: FD: %d, WARNING: Pinset validation failure!\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd); STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd);
preverify_ok = 0; preverify_ok = 0;
upstream->tls_auth_failed = 1; upstream->tls_auth_failed = 1;
if (upstream->tls_fallback_ok) if (upstream->tls_fallback_ok)
DEBUG_STUB("%s %-30s: FD: %d, WARNING: Proceeding even though pinset validation failed!\n", DEBUG_STUB("%s %-35s: FD: %d, WARNING: Proceeding even though pinset validation failed!\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd); STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd);
} }
/* If fallback is allowed, proceed regardless of what the auth error is /* If fallback is allowed, proceed regardless of what the auth error is
@ -941,7 +941,7 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
/* If we have a hostname, always use it */ /* If we have a hostname, always use it */
if (upstream->tls_auth_name[0] != '\0') { if (upstream->tls_auth_name[0] != '\0') {
/*Request certificate for the auth_name*/ /*Request certificate for the auth_name*/
DEBUG_STUB("%s %-30s: Hostname verification requested for: %s\n", DEBUG_STUB("%s %-35s: Hostname verification requested for: %s\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->tls_auth_name); STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->tls_auth_name);
SSL_set_tlsext_host_name(ssl, upstream->tls_auth_name); SSL_set_tlsext_host_name(ssl, upstream->tls_auth_name);
#ifdef HAVE_SSL_HN_AUTH #ifdef HAVE_SSL_HN_AUTH
@ -953,7 +953,7 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
#else #else
if (dnsreq->netreqs[0]->tls_auth_min == GETDNS_AUTHENTICATION_REQUIRED) { if (dnsreq->netreqs[0]->tls_auth_min == GETDNS_AUTHENTICATION_REQUIRED) {
/* TODO: Trigger post-handshake custom validation*/ /* TODO: Trigger post-handshake custom validation*/
DEBUG_STUB("%s %-30s: ERROR: TLS Authentication functionality not available\n", DEBUG_STUB("%s %-35s: ERROR: TLS Authentication functionality not available\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__); STUB_DEBUG_SETUP_TLS, __FUNCTION__);
upstream->tls_hs_state = GETDNS_HS_FAILED; upstream->tls_hs_state = GETDNS_HS_FAILED;
upstream->tls_auth_failed = 1; upstream->tls_auth_failed = 1;
@ -968,10 +968,10 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
* TLS is specified and we have no pubkey_pinset */ * TLS is specified and we have no pubkey_pinset */
if (dnsreq->netreqs[0]->tls_auth_min == GETDNS_AUTHENTICATION_REQUIRED) { if (dnsreq->netreqs[0]->tls_auth_min == GETDNS_AUTHENTICATION_REQUIRED) {
if (upstream->tls_pubkey_pinset) { if (upstream->tls_pubkey_pinset) {
DEBUG_STUB("%s %-30s: Proceeding with only pubkey pinning authentication\n", DEBUG_STUB("%s %-35s: Proceeding with only pubkey pinning authentication\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__); STUB_DEBUG_SETUP_TLS, __FUNCTION__);
} else { } else {
DEBUG_STUB("%s %-30s: ERROR: No host name or pubkey pinset provided for TLS authentication\n", DEBUG_STUB("%s %-35s: ERROR: No host name or pubkey pinset provided for TLS authentication\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__); STUB_DEBUG_SETUP_TLS, __FUNCTION__);
upstream->tls_hs_state = GETDNS_HS_FAILED; upstream->tls_hs_state = GETDNS_HS_FAILED;
upstream->tls_auth_failed = 1; upstream->tls_auth_failed = 1;
@ -979,7 +979,7 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
} }
} else { } else {
/* no hostname verification, so we will make opportunistic connections */ /* no hostname verification, so we will make opportunistic connections */
DEBUG_STUB("%s %-30s: Proceeding even though no hostname provided!\n", DEBUG_STUB("%s %-35s: Proceeding even though no hostname provided!\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__); STUB_DEBUG_SETUP_TLS, __FUNCTION__);
upstream->tls_auth_failed = 1; upstream->tls_auth_failed = 1;
upstream->tls_fallback_ok = 1; upstream->tls_fallback_ok = 1;
@ -987,10 +987,10 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
} }
if (upstream->tls_fallback_ok) { if (upstream->tls_fallback_ok) {
SSL_set_cipher_list(ssl, "DEFAULT"); SSL_set_cipher_list(ssl, "DEFAULT");
DEBUG_STUB("%s %-30s: WARNING: Using Oppotunistic TLS (fallback allowed)!\n", DEBUG_STUB("%s %-35s: WARNING: Using Oppotunistic TLS (fallback allowed)!\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__); STUB_DEBUG_SETUP_TLS, __FUNCTION__);
} else } else
DEBUG_STUB("%s %-30s: Using Strict TLS \n", STUB_DEBUG_SETUP_TLS, DEBUG_STUB("%s %-35s: Using Strict TLS \n", STUB_DEBUG_SETUP_TLS,
__FUNCTION__); __FUNCTION__);
SSL_set_verify(ssl, SSL_VERIFY_PEER, tls_verify_callback); SSL_set_verify(ssl, SSL_VERIFY_PEER, tls_verify_callback);
@ -1002,7 +1002,7 @@ tls_create_object(getdns_dns_req *dnsreq, int fd, getdns_upstream *upstream)
static int static int
tls_do_handshake(getdns_upstream *upstream) tls_do_handshake(getdns_upstream *upstream)
{ {
DEBUG_STUB("%s %-30s: FD: %d \n", STUB_DEBUG_SETUP_TLS, DEBUG_STUB("%s %-35s: FD: %d \n", STUB_DEBUG_SETUP_TLS,
__FUNCTION__, upstream->fd); __FUNCTION__, upstream->fd);
int r; int r;
int want; int want;
@ -1049,14 +1049,14 @@ tls_do_handshake(getdns_upstream *upstream)
upstream->tls_hs_state = GETDNS_HS_WRITE; upstream->tls_hs_state = GETDNS_HS_WRITE;
return STUB_TCP_AGAIN; return STUB_TCP_AGAIN;
default: default:
DEBUG_STUB("%s %-30s: FD: %d Handshake failed %d\n", DEBUG_STUB("%s %-35s: FD: %d Handshake failed %d\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd, STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd,
want); want);
return tls_cleanup(upstream); return tls_cleanup(upstream);
} }
} }
upstream->tls_hs_state = GETDNS_HS_DONE; upstream->tls_hs_state = GETDNS_HS_DONE;
DEBUG_STUB("%s %-30s: FD: %d Handshake succeeded\n", DEBUG_STUB("%s %-35s: FD: %d Handshake succeeded\n",
STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd); STUB_DEBUG_SETUP_TLS, __FUNCTION__, upstream->fd);
r = SSL_get_verify_result(upstream->tls_obj); r = SSL_get_verify_result(upstream->tls_obj);
if (upstream->tls_auth_name[0]) if (upstream->tls_auth_name[0])
@ -1251,7 +1251,7 @@ stub_tls_write(getdns_upstream *upstream, getdns_tcp_state *tcp,
netreq->owner->context->idle_timeout != 0) { netreq->owner->context->idle_timeout != 0) {
/* Add the keepalive option to every nth query on this /* Add the keepalive option to every nth query on this
connection */ connection */
DEBUG_STUB("%s %-30s: FD: %d Requesting keepalive \n", DEBUG_STUB("%s %-35s: FD: %d Requesting keepalive \n",
STUB_DEBUG_SETUP, __FUNCTION__, upstream->fd); STUB_DEBUG_SETUP, __FUNCTION__, upstream->fd);
if (attach_edns_keepalive(netreq)) if (attach_edns_keepalive(netreq))
return STUB_OUT_OF_OPTIONS; return STUB_OUT_OF_OPTIONS;
@ -1312,7 +1312,7 @@ stub_udp_read_cb(void *userarg)
getdns_dns_req *dnsreq = netreq->owner; getdns_dns_req *dnsreq = netreq->owner;
getdns_upstream *upstream = netreq->upstream; getdns_upstream *upstream = netreq->upstream;
ssize_t read; ssize_t read;
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_READ, DEBUG_STUB("%s %-35s: MSG: %p \n", STUB_DEBUG_READ,
__FUNCTION__, netreq); __FUNCTION__, netreq);
GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event); GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event);
@ -1340,7 +1340,7 @@ stub_udp_read_cb(void *userarg)
close(netreq->fd); close(netreq->fd);
while (GLDNS_TC_WIRE(netreq->response)) { while (GLDNS_TC_WIRE(netreq->response)) {
DEBUG_STUB("%s %-30s: MSG: %p TC bit set in response \n", STUB_DEBUG_READ, DEBUG_STUB("%s %-35s: MSG: %p TC bit set in response \n", STUB_DEBUG_READ,
__FUNCTION__, netreq); __FUNCTION__, netreq);
if (!(netreq->transport_current < netreq->transport_count)) if (!(netreq->transport_current < netreq->transport_count))
break; break;
@ -1375,7 +1375,7 @@ stub_udp_write_cb(void *userarg)
getdns_network_req *netreq = (getdns_network_req *)userarg; getdns_network_req *netreq = (getdns_network_req *)userarg;
getdns_dns_req *dnsreq = netreq->owner; getdns_dns_req *dnsreq = netreq->owner;
size_t pkt_len; size_t pkt_len;
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_WRITE, DEBUG_STUB("%s %-35s: MSG: %p \n", STUB_DEBUG_WRITE,
__FUNCTION__, netreq); __FUNCTION__, netreq);
GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event); GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event);
@ -1420,7 +1420,7 @@ static void
upstream_read_cb(void *userarg) upstream_read_cb(void *userarg)
{ {
getdns_upstream *upstream = (getdns_upstream *)userarg; getdns_upstream *upstream = (getdns_upstream *)userarg;
DEBUG_STUB("%s %-30s: FD: %d \n", STUB_DEBUG_READ, __FUNCTION__, DEBUG_STUB("%s %-35s: FD: %d \n", STUB_DEBUG_READ, __FUNCTION__,
upstream->fd); upstream->fd);
getdns_network_req *netreq; getdns_network_req *netreq;
int q; int q;
@ -1459,6 +1459,8 @@ upstream_read_cb(void *userarg)
return; return;
} }
DEBUG_STUB("%s %-35s: MSG: %p (read)\n", STUB_DEBUG_READ, __FUNCTION__,
netreq);
netreq->state = NET_REQ_FINISHED; netreq->state = NET_REQ_FINISHED;
netreq->response = upstream->tcp.read_buf; netreq->response = upstream->tcp.read_buf;
netreq->response_len = netreq->response_len =
@ -1500,7 +1502,7 @@ upstream_read_cb(void *userarg)
static void static void
netreq_upstream_read_cb(void *userarg) netreq_upstream_read_cb(void *userarg)
{ {
DEBUG_STUB("%s %-30s: FD: %d \n", STUB_DEBUG_READ, DEBUG_STUB("%s %-35s: FD: %d \n", STUB_DEBUG_READ,
__FUNCTION__, ((getdns_network_req *)userarg)->upstream->fd); __FUNCTION__, ((getdns_network_req *)userarg)->upstream->fd);
upstream_read_cb(((getdns_network_req *)userarg)->upstream); upstream_read_cb(((getdns_network_req *)userarg)->upstream);
} }
@ -1521,7 +1523,7 @@ upstream_write_cb(void *userarg)
dnsreq = netreq->owner; dnsreq = netreq->owner;
/* TODO: think about TCP AGAIN */ /* TODO: think about TCP AGAIN */
netreq->debug_start_time = _getdns_get_time_as_uintt64(); netreq->debug_start_time = _getdns_get_time_as_uintt64();
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_WRITE, DEBUG_STUB("%s %-35s: MSG: %p (writing)\n", STUB_DEBUG_WRITE,
__FUNCTION__, netreq); __FUNCTION__, netreq);
if (tls_requested(netreq) && tls_should_write(upstream)) if (tls_requested(netreq) && tls_should_write(upstream))
@ -1539,7 +1541,7 @@ upstream_write_cb(void *userarg)
case STUB_TCP_ERROR: case STUB_TCP_ERROR:
/* Problem with the TCP connection itself. Need to fallback.*/ /* Problem with the TCP connection itself. Need to fallback.*/
DEBUG_STUB("%s %-30s: MSG: %p ERROR!\n", STUB_DEBUG_WRITE, DEBUG_STUB("%s %-35s: MSG: %p ERROR!\n", STUB_DEBUG_WRITE,
__FUNCTION__, ((getdns_network_req *)userarg)); __FUNCTION__, ((getdns_network_req *)userarg));
upstream->tcp.write_error = 1; upstream->tcp.write_error = 1;
/* Use policy of trying next upstream in this case. Need more work on /* Use policy of trying next upstream in this case. Need more work on
@ -1599,7 +1601,7 @@ upstream_write_cb(void *userarg)
static void static void
netreq_upstream_write_cb(void *userarg) netreq_upstream_write_cb(void *userarg)
{ {
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_WRITE, DEBUG_STUB("%s %-35s: MSG: %p (catch event)\n", STUB_DEBUG_WRITE,
__FUNCTION__, ((getdns_network_req *)userarg)); __FUNCTION__, ((getdns_network_req *)userarg));
upstream_write_cb(((getdns_network_req *)userarg)->upstream); upstream_write_cb(((getdns_network_req *)userarg)->upstream);
} }
@ -1650,13 +1652,13 @@ upstream_select(getdns_network_req *netreq, getdns_transport_list_t transport)
/* TODO[TLS]: Should we create a tmp array of upstreams with correct*/ /* TODO[TLS]: Should we create a tmp array of upstreams with correct*/
/* transport type and/or maintain separate current for transports?*/ /* transport type and/or maintain separate current for transports?*/
i = upstreams->current; i = upstreams->current;
DEBUG_STUB("%s %-30s: Starting from upstream: %d of %d available \n", STUB_DEBUG_SETUP, DEBUG_STUB("%s %-35s: Starting from upstream: %d of %d available \n", STUB_DEBUG_SETUP,
__FUNCTION__, (int)i, (int)upstreams->count); __FUNCTION__, (int)i, (int)upstreams->count);
do { do {
if (upstreams->upstreams[i].to_retry > 0 && if (upstreams->upstreams[i].to_retry > 0 &&
upstream_transport_valid(&upstreams->upstreams[i], transport, netreq)) { upstream_transport_valid(&upstreams->upstreams[i], transport, netreq)) {
upstreams->current = i; upstreams->current = i;
DEBUG_STUB("%s %-30s: Selected upstream: %d %p transport: %d\n", DEBUG_STUB("%s %-35s: Selected upstream: %d %p transport: %d\n",
STUB_DEBUG_SETUP, __FUNCTION__, (int)i, STUB_DEBUG_SETUP, __FUNCTION__, (int)i,
&upstreams->upstreams[i], transport); &upstreams->upstreams[i], transport);
return &upstreams->upstreams[i]; return &upstreams->upstreams[i];
@ -1673,7 +1675,7 @@ upstream_select(getdns_network_req *netreq, getdns_transport_list_t transport)
/* Need to check again that the transport is valid */ /* Need to check again that the transport is valid */
if (!upstream_transport_valid(upstream, transport, netreq)) { if (!upstream_transport_valid(upstream, transport, netreq)) {
DEBUG_STUB("%s %-30s: No valid upstream available for transport %d!\n", DEBUG_STUB("%s %-35s: No valid upstream available for transport %d!\n",
STUB_DEBUG_SETUP, __FUNCTION__, transport); STUB_DEBUG_SETUP, __FUNCTION__, transport);
return NULL; return NULL;
} }
@ -1688,7 +1690,7 @@ int
upstream_connect(getdns_upstream *upstream, getdns_transport_list_t transport, upstream_connect(getdns_upstream *upstream, getdns_transport_list_t transport,
getdns_dns_req *dnsreq) getdns_dns_req *dnsreq)
{ {
DEBUG_STUB("%s %-30s: Checking upstream connection: %p\n", STUB_DEBUG_SETUP, DEBUG_STUB("%s %-35s: Checking upstream connection: %p\n", STUB_DEBUG_SETUP,
__FUNCTION__, upstream); __FUNCTION__, upstream);
int fd = -1; int fd = -1;
switch(transport) { switch(transport) {
@ -1740,7 +1742,7 @@ upstream_find_for_transport(getdns_network_req *netreq,
if (!upstream) if (!upstream)
return NULL; return NULL;
*fd = upstream_connect(upstream, transport, netreq->owner); *fd = upstream_connect(upstream, transport, netreq->owner);
DEBUG_STUB("%s %-30s: FD: %d Connected for upstream: %p\n", DEBUG_STUB("%s %-35s: FD: %d Connected for upstream: %p\n",
STUB_DEBUG_SETUP, __FUNCTION__, *fd, upstream); STUB_DEBUG_SETUP, __FUNCTION__, *fd, upstream);
return upstream; return upstream;
} }
@ -1775,7 +1777,7 @@ fallback_on_write(getdns_network_req *netreq)
/* Deal with UDP and change error code*/ /* Deal with UDP and change error code*/
DEBUG_STUB("%s %-30s: MSG: %p FALLING BACK \n", STUB_DEBUG_SCHEDULE, __FUNCTION__, netreq); DEBUG_STUB("%s %-35s: MSG: %p FALLING BACK \n", STUB_DEBUG_SCHEDULE, __FUNCTION__, netreq);
getdns_upstream *upstream = netreq->upstream; getdns_upstream *upstream = netreq->upstream;
/* Try to find a fallback transport*/ /* Try to find a fallback transport*/
@ -1797,7 +1799,7 @@ fallback_on_write(getdns_network_req *netreq)
static void static void
upstream_reschedule_events(getdns_upstream *upstream, size_t idle_timeout) { upstream_reschedule_events(getdns_upstream *upstream, size_t idle_timeout) {
DEBUG_STUB("%s %-30s: FD: %d \n", STUB_DEBUG_SCHEDULE, DEBUG_STUB("%s %-35s: FD: %d \n", STUB_DEBUG_SCHEDULE,
__FUNCTION__, upstream->fd); __FUNCTION__, upstream->fd);
GETDNS_CLEAR_EVENT(upstream->loop, &upstream->event); GETDNS_CLEAR_EVENT(upstream->loop, &upstream->event);
if (!upstream->write_queue && upstream->event.write_cb) { if (!upstream->write_queue && upstream->event.write_cb) {
@ -1816,7 +1818,7 @@ upstream_reschedule_events(getdns_upstream *upstream, size_t idle_timeout) {
GETDNS_SCHEDULE_EVENT(upstream->loop, GETDNS_SCHEDULE_EVENT(upstream->loop,
upstream->fd, TIMEOUT_FOREVER, &upstream->event); upstream->fd, TIMEOUT_FOREVER, &upstream->event);
else { else {
DEBUG_STUB("%s %-30s: FD: %d Connection idle \n", DEBUG_STUB("%s %-35s: FD: %d Connection idle \n",
STUB_DEBUG_SCHEDULE, __FUNCTION__, upstream->fd); STUB_DEBUG_SCHEDULE, __FUNCTION__, upstream->fd);
upstream->event.timeout_cb = upstream_idle_timeout_cb; upstream->event.timeout_cb = upstream_idle_timeout_cb;
if (upstream->tcp.write_error != 0) if (upstream->tcp.write_error != 0)
@ -1830,7 +1832,7 @@ static void
upstream_reschedule_netreq_events(getdns_upstream *upstream, upstream_reschedule_netreq_events(getdns_upstream *upstream,
getdns_network_req *netreq) { getdns_network_req *netreq) {
if (netreq) { if (netreq) {
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_SCHEDULE, __FUNCTION__, DEBUG_STUB("%s %-35s: MSG: %p \n", STUB_DEBUG_SCHEDULE, __FUNCTION__,
netreq); netreq);
getdns_dns_req *dnsreq = netreq->owner; getdns_dns_req *dnsreq = netreq->owner;
GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event); GETDNS_CLEAR_EVENT(dnsreq->loop, &netreq->event);
@ -1852,7 +1854,7 @@ upstream_reschedule_netreq_events(getdns_upstream *upstream,
* req the conneciton is no longer idle so probably better to re-use * req the conneciton is no longer idle so probably better to re-use
* than shut and immediately open a new one! * than shut and immediately open a new one!
* So we will have to be aggressive and shut the connection....*/ * So we will have to be aggressive and shut the connection....*/
DEBUG_STUB("%s %-30s: FD: %d Closing connection!\n", DEBUG_STUB("%s %-35s: FD: %d Closing connection!\n",
STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd); STUB_DEBUG_CLEANUP, __FUNCTION__, upstream->fd);
_getdns_upstream_shutdown(upstream); _getdns_upstream_shutdown(upstream);
} }
@ -1861,7 +1863,7 @@ upstream_reschedule_netreq_events(getdns_upstream *upstream,
static void static void
upstream_schedule_netreq(getdns_upstream *upstream, getdns_network_req *netreq) upstream_schedule_netreq(getdns_upstream *upstream, getdns_network_req *netreq)
{ {
DEBUG_STUB("%s %-30s: MSG: %p \n", STUB_DEBUG_SCHEDULE, __FUNCTION__, netreq); DEBUG_STUB("%s %-35s: MSG: %p (schedule event)\n", STUB_DEBUG_SCHEDULE, __FUNCTION__, netreq);
/* We have a connected socket and a global event loop */ /* We have a connected socket and a global event loop */
assert(upstream->fd >= 0); assert(upstream->fd >= 0);
assert(upstream->loop); assert(upstream->loop);
@ -1893,7 +1895,7 @@ upstream_schedule_netreq(getdns_upstream *upstream, getdns_network_req *netreq)
getdns_return_t getdns_return_t
_getdns_submit_stub_request(getdns_network_req *netreq) _getdns_submit_stub_request(getdns_network_req *netreq)
{ {
DEBUG_STUB("%s %-30s: MSG: %p TYPE: %d\n", STUB_DEBUG_ENTRY, __FUNCTION__, DEBUG_STUB("%s %-35s: MSG: %p TYPE: %d\n", STUB_DEBUG_ENTRY, __FUNCTION__,
netreq, netreq->request_type); netreq, netreq->request_type);
int fd = -1; int fd = -1;
getdns_dns_req *dnsreq = netreq->owner; getdns_dns_req *dnsreq = netreq->owner;