Log messages about trust anchor fetching and installing

This commit is contained in:
Willem Toorop 2018-12-13 14:23:32 +01:00
parent 91a3a3db36
commit 41f4940072
5 changed files with 301 additions and 197 deletions

View File

@ -703,7 +703,7 @@ static uint8_t *tas_validate(struct mem_funcs *mf,
success = NULL;
}
} else
DEBUG_ANCHOR("Could not allocate space for "
DEBUG_ANCHOR("Cannot allocate space for "
"trust anchors\n");
} else {
success = tas;
@ -736,57 +736,71 @@ void _getdns_context_equip_with_anchor(
if ((r = getdns_context_get_trust_anchors_verify_CA(
context, &verify_CA)))
DEBUG_ANCHOR("ERROR %s(): Getting trust anchor verify"
" CA: \"%s\"\n", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify CA: \"%s\"\n"
, getdns_get_errorstr_by_id(r));
else if (!verify_CA || !*verify_CA)
DEBUG_ANCHOR("NOTICE: Trust anchor verification explicitely "
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Trust anchor verification explicitely "
"disabled by empty verify CA\n");
else if ((r = getdns_context_get_trust_anchors_verify_email(
context, &verify_email)))
DEBUG_ANCHOR("ERROR %s(): Getting trust anchor verify email "
"address: \"%s\"\n", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify email address: "
"\"%s\"\n", getdns_get_errorstr_by_id(r));
else if (!verify_email || !*verify_email)
DEBUG_ANCHOR("NOTICE: Trust anchor verification explicitely "
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Trust anchor verification explicitely "
"disabled by empty verify email\n");
else if (!(xml_data = _getdns_context_get_priv_file(context,
"root-anchors.xml", xml_spc, sizeof(xml_spc), &xml_len)))
DEBUG_ANCHOR("DEBUG %s(): root-anchors.xml not present\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "root-anchors.xml not present\n");
else if (!(p7s_data = _getdns_context_get_priv_file(context,
"root-anchors.p7s", p7s_spc, sizeof(p7s_spc), &p7s_len)))
DEBUG_ANCHOR("DEBUG %s(): root-anchors.p7s not present\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "root-anchors.xml not present\n");
else if (!(xml = BIO_new_mem_buf(xml_data, xml_len)))
DEBUG_ANCHOR("ERROR %s(): Failed allocating xml BIO\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Failed allocating xml BIO\n");
else if (!(p7s = BIO_new_mem_buf(p7s_data, p7s_len)))
DEBUG_ANCHOR("ERROR %s(): Failed allocating p7s BIO\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Failed allocating p7s BIO\n");
else if (!(crt = BIO_new_mem_buf((void *)verify_CA, -1)))
DEBUG_ANCHOR("ERROR %s(): Failed allocating crt BIO\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Failed allocating crt BIO\n");
else if (!(x = PEM_read_bio_X509(crt, NULL, 0, NULL)))
DEBUG_ANCHOR("ERROR %s(): Parsing builtin certificate\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot parse builtin certificate\n");
else if (!(store = X509_STORE_new()))
DEBUG_ANCHOR("ERROR %s(): Failed allocating store\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Failed allocating X509 store\n");
else if (!X509_STORE_add_cert(store, x))
DEBUG_ANCHOR("ERROR %s(): Adding certificate to store\n"
, __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot add certificate to X509 store\n");
else if (_getdns_verify_p7sig(xml, p7s, store, verify_email)) {
uint8_t ta_spc[sizeof(context->trust_anchors_spc)];
@ -799,15 +813,21 @@ void _getdns_context_equip_with_anchor(
if (!_getdns_parse_xml_trust_anchors_buf(&gbuf, now_ms,
(char *)xml_data, xml_len))
DEBUG_ANCHOR("Failed to parse trust anchor XML data");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Failed to parse trust anchor XML data\n");
else if ((ta_len = gldns_buffer_position(&gbuf)) > sizeof(ta_spc)) {
if ((ta = GETDNS_XMALLOC(context->mf, uint8_t, ta_len))) {
gldns_buffer_init_frm_data(&gbuf, ta,
gldns_buffer_position(&gbuf));
if (!_getdns_parse_xml_trust_anchors_buf(
&gbuf, now_ms, (char *)xml_data, xml_len)) {
DEBUG_ANCHOR("Failed to re-parse trust"
" anchor XML data");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR
, GETDNS_LOG_ERR
, "Error re-parsing trust "
"anchor XML data\n");
GETDNS_FREE(context->mf, ta);
} else {
context->trust_anchors = ta;
@ -816,7 +836,11 @@ void _getdns_context_equip_with_anchor(
_getdns_ta_notify_dnsreqs(context);
}
} else
DEBUG_ANCHOR("Could not allocate space for XML file");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR
, GETDNS_LOG_ERR
, "Cannot allocate space for "
"XML file");
} else {
(void)memcpy(context->trust_anchors_spc, ta_spc, ta_len);
context->trust_anchors = context->trust_anchors_spc;
@ -828,7 +852,9 @@ void _getdns_context_equip_with_anchor(
(void *)context->trust_anchors, (int)context->trust_anchors_len);
} else {
DEBUG_ANCHOR("Verifying trust-anchors failed!\n");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Verifying trust-anchors XML failed!\n");
}
if (store) X509_STORE_free(store);
if (x) X509_free(x);
@ -855,10 +881,8 @@ static const char tas_write_xml_p7s_buf[] =
"\r\n";
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
static inline const char * rt_str(uint16_t rt)
{ return rt == GETDNS_RRTYPE_A ? "A" : rt == GETDNS_RRTYPE_AAAA ? "AAAA" : "?"; }
#endif
static int tas_busy(tas_connection *a)
{
@ -905,7 +929,8 @@ static void tas_success(getdns_context *context, tas_connection *a)
tas_cleanup(context, a);
tas_cleanup(context, other);
DEBUG_ANCHOR("Successfully fetched new trust anchors\n");
_getdns_log( &context->log, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Successfully fetched new trust anchors\n");
context->trust_anchors_source = GETDNS_TASRC_XML;
_getdns_ta_notify_dnsreqs(context);
}
@ -913,22 +938,26 @@ static void tas_success(getdns_context *context, tas_connection *a)
static void tas_fail(getdns_context *context, tas_connection *a)
{
tas_connection *other = &context->a == a ? &context->aaaa : &context->a;
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
uint16_t rt = &context->a == a ? GETDNS_RRTYPE_A : GETDNS_RRTYPE_AAAA;
uint16_t ort = rt == GETDNS_RRTYPE_A ? GETDNS_RRTYPE_AAAA : GETDNS_RRTYPE_A;
#endif
tas_cleanup(context, a);
if (!tas_busy(other)) {
DEBUG_ANCHOR("Fatal error fetching trust anchor: "
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Fatal error fetching trust anchor: "
"%s connection failed too\n", rt_str(rt));
context->trust_anchors_source = GETDNS_TASRC_FAILED;
context->trust_anchors_backoff_expiry =
_getdns_get_now_ms() + context->trust_anchors_backoff_time;
_getdns_ta_notify_dnsreqs(context);
} else
DEBUG_ANCHOR("%s connection failed, waiting for %s\n"
, rt_str(rt), rt_str(ort));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "%s connection failed, waiting for %s\n"
, rt_str(rt)
, rt_str( rt == GETDNS_RRTYPE_A
? GETDNS_RRTYPE_AAAA : GETDNS_RRTYPE_A));
}
static void tas_connect(getdns_context *context, tas_connection *a);
@ -960,7 +989,9 @@ static void tas_timeout_cb(void *userarg)
a = &context->a;
else a = &context->aaaa;
DEBUG_ANCHOR("Trust anchor fetch timeout\n");
_getdns_log( &context->log, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "Trust anchor fetch timeout\n");
GETDNS_CLEAR_EVENT(a->loop, &a->event);
tas_next(context, a);
}
@ -976,7 +1007,9 @@ static void tas_reconnect_cb(void *userarg)
a = &context->a;
else a = &context->aaaa;
DEBUG_ANCHOR("Waiting for second document timeout. Reconnecting...\n");
_getdns_log( &context->log, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "Waiting for second document timeout. Reconnecting...\n");
GETDNS_CLEAR_EVENT(a->loop, &a->event);
close(a->fd);
a->fd = -1;
@ -991,8 +1024,6 @@ static void tas_read_cb(void *userarg);
static void tas_write_cb(void *userarg);
static void tas_doc_read(getdns_context *context, tas_connection *a)
{
DEBUG_ANCHOR("doc (size: %d)\n", (int)a->tcp.read_buf_len);
assert(a->tcp.read_pos == a->tcp.read_buf + a->tcp.read_buf_len);
assert(context);
@ -1021,18 +1052,20 @@ static void tas_doc_read(getdns_context *context, tas_connection *a)
if ((r = getdns_context_get_trust_anchors_verify_CA(
context, (const char **)&verify_CA.data)))
DEBUG_ANCHOR("ERROR %s(): Getting trust anchor verify"
" CA: \"%s\"\n", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify CA: "
"\"%s\"\n", getdns_get_errorstr_by_id(r));
else if (!(verify_CA.size = strlen((const char *)verify_CA.data)))
; /* pass */
else if ((r = getdns_context_get_trust_anchors_verify_email(
context, &verify_email)))
DEBUG_ANCHOR("ERROR %s(): Getting trust anchor verify"
" email address: \"%s\"\n", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify email: "
"\"%s\"\n", getdns_get_errorstr_by_id(r));
else if (!(tas = tas_validate(&context->mf, &a->xml, &p7s_bd,
&verify_CA, verify_email, &now_ms, tas, &tas_len)))
@ -1157,7 +1190,11 @@ static void tas_read_cb(void *userarg)
DEBUG_ANCHOR("i: %d, n: %d, doc_len: %d\n"
, (int)i, (int)n, doc_len);
if (!doc)
DEBUG_ANCHOR("Memory error");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR
, GETDNS_LOG_ERR
, "Memory error while reading "
"trust anchor\n");
else {
ssize_t surplus = n - i;
@ -1204,7 +1241,11 @@ static void tas_read_cb(void *userarg)
} else if (_getdns_socketerror_wants_retry())
return;
DEBUG_ANCHOR("Read error: %d %s\n", (int)n, _getdns_errnostr());
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error while receiving trust anchor: %s\n"
, _getdns_errnostr());
GETDNS_CLEAR_EVENT(a->loop, &a->event);
tas_next(context, a);
}
@ -1254,7 +1295,9 @@ static void tas_write_cb(void *userarg)
} else if (_getdns_socketerror_wants_retry())
return;
DEBUG_ANCHOR("Write error: %s\n", _getdns_errnostr());
_getdns_log( &context->log, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error while sending to trust anchor site: %s\n"
, _getdns_errnostr());
GETDNS_CLEAR_EVENT(a->loop, &a->event);
tas_next(context, a);
}
@ -1293,9 +1336,7 @@ static getdns_return_t _getdns_get_tas_url_hostname(
static void tas_connect(getdns_context *context, tas_connection *a)
{
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
char a_buf[40];
#endif
int r;
#ifdef HAVE_FCNTL
@ -1311,15 +1352,19 @@ static void tas_connect(getdns_context *context, tas_connection *a)
tas_next(context, a);
return;
}
DEBUG_ANCHOR("Initiating connection to %s\n"
, inet_ntop(( a->req->request_type == GETDNS_RRTYPE_A
? AF_INET : AF_INET6)
, a->rr->rr_i.rr_type + 10, a_buf, sizeof(a_buf)));
_getdns_log( &context->log, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "Setting op connection to: %s\n"
, inet_ntop( ( a->req->request_type == GETDNS_RRTYPE_A
? AF_INET : AF_INET6)
, a->rr->rr_i.rr_type + 10
, a_buf, sizeof(a_buf)));
if ((a->fd = socket(( a->req->request_type == GETDNS_RRTYPE_A
? AF_INET : AF_INET6), SOCK_STREAM, IPPROTO_TCP)) == -1) {
DEBUG_ANCHOR("Error creating socket: %s\n",
_getdns_errnostr());
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error creating socket: %s\n", _getdns_errnostr());
tas_next(context, a);
return;
}
@ -1370,9 +1415,11 @@ static void tas_connect(getdns_context *context, tas_connection *a)
}
if ((R = _getdns_get_tas_url_hostname(
context, tas_hostname, &path))) {
DEBUG_ANCHOR("ERROR %s(): Could not get_tas_url_hostname"
": \"%s\"", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get hostname from trust anchor "
"url: \"%s\"\n"
, getdns_get_errorstr_by_id(r));
goto error;
}
hostname_len = strlen(tas_hostname);
@ -1380,8 +1427,10 @@ static void tas_connect(getdns_context *context, tas_connection *a)
tas_hostname[--hostname_len] = '\0';
path_len = strlen(path);
if (path_len < 4) {
DEBUG_ANCHOR("ERROR %s(): path of tas_url \"%s\" too "
"small\n", __FUNC__, path);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Trust anchor path \"%s\" too small\n"
, path);
goto error;
}
if (a->state == TAS_RETRY_GET_PS7) {
@ -1394,8 +1443,10 @@ static void tas_connect(getdns_context *context, tas_connection *a)
fmt = tas_write_xml_p7s_buf;
}
if (!(write_buf = GETDNS_XMALLOC(context->mf, char, buf_sz))) {
DEBUG_ANCHOR("ERROR %s(): Could not allocate write "
"buffer\n", __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot allocate write buffer for "
"sending to trust anchor host\n");
goto error;
}
if (a->state == TAS_RETRY_GET_PS7) {
@ -1429,8 +1480,10 @@ static void tas_connect(getdns_context *context, tas_connection *a)
DEBUG_ANCHOR("Scheduled write with event\n");
return;
} else
DEBUG_ANCHOR("Connect error: %s\n", _getdns_errnostr());
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error connecting to trust anchor host: %s\n "
, _getdns_errnostr());
error:
tas_next(context, a);
}
@ -1444,7 +1497,10 @@ static void tas_happy_eyeballs_cb(void *userarg)
if (tas_fetching(&context->aaaa))
return;
else {
DEBUG_ANCHOR("AAAA came too late, clearing Happy Eyeballs timer\n");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "Too late reception of AAAA for trust anchor "
"host for Happy Eyeballs\n");
GETDNS_CLEAR_EVENT(context->a.loop, &context->a.event);
tas_connect(context, &context->a);
}
@ -1463,28 +1519,31 @@ static void _tas_hostname_lookup_cb(getdns_dns_req *dnsreq)
&a->rrset_spc, a->req->response, a->req->response_len);
if (!a->rrset) {
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
char tas_hostname[256] = "<no hostname>";
(void) _getdns_get_tas_url_hostname(context, tas_hostname, NULL);
DEBUG_ANCHOR("%s lookup for %s returned no response\n"
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "%s lookup for %s returned no response\n"
, rt_str(a->req->request_type), tas_hostname);
#endif
} else if (a->req->response_len < dnsreq->name_len + 12 ||
!_getdns_dname_equal(a->req->response + 12, dnsreq->name) ||
a->rrset->rr_type != a->req->request_type) {
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
char tas_hostname[256] = "<no hostname>";
(void) _getdns_get_tas_url_hostname(context, tas_hostname, NULL);
DEBUG_ANCHOR("%s lookup for %s returned wrong response\n"
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "%s lookup for %s returned wrong response\n"
, rt_str(a->req->request_type), tas_hostname);
#endif
} else if (!(a->rr = _getdns_rrtype_iter_init(&a->rr_spc, a->rrset))) {
#if defined(ANCHOR_DEBUG) && ANCHOR_DEBUG
char tas_hostname[256] = "<no hostname>";
(void) _getdns_get_tas_url_hostname(context, tas_hostname, NULL);
DEBUG_ANCHOR("%s lookup for %s returned no addresses\n"
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "%s lookup for %s returned no addresses\n"
, rt_str(a->req->request_type), tas_hostname);
#endif
} else {
tas_connection *other = a == &context->a ? &context->aaaa
: &context->a;
@ -1494,8 +1553,9 @@ static void _tas_hostname_lookup_cb(getdns_dns_req *dnsreq)
; /* pass */
else if (a == &context->a && tas_busy(other)) {
DEBUG_ANCHOR("Postponing connection initiation: "
"Happy Eyeballs\n");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "Waiting 25ms for AAAA to arrive\n");
GETDNS_SCHEDULE_EVENT(a->loop, a->fd, 25,
getdns_eventloop_event_init(&a->event,
a->req->owner, NULL, NULL, tas_happy_eyeballs_cb));
@ -1522,38 +1582,47 @@ void _getdns_start_fetching_ta(
const char *verify_email;
if ((r = _getdns_get_tas_url_hostname(context, tas_hostname, NULL))) {
DEBUG_ANCHOR("ERROR %s(): Could not get_tas_url_hostname"
": \"%s\"", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get hostname from trust anchor url: "
"\"%s\"\n", getdns_get_errorstr_by_id(r));
return;
} else if ((r = getdns_context_get_trust_anchors_verify_CA(
context, &verify_CA))) {
DEBUG_ANCHOR("ERROR %s(): Could not get verify CA"
": \"%s\"", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify CA: \"%s\"\n"
, getdns_get_errorstr_by_id(r));
return;
} else if (!verify_CA || !*verify_CA) {
DEBUG_ANCHOR("NOTICE: Trust anchor fetching explicitely "
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Trust anchor verification explicitely "
"disabled by empty verify CA\n");
return;
} else if ((r = getdns_context_get_trust_anchors_verify_email(
context, &verify_email))) {
DEBUG_ANCHOR("ERROR %s(): Could not get verify email address"
": \"%s\"", __FUNC__
, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Cannot get trust anchor verify email: \"%s\"\n"
, getdns_get_errorstr_by_id(r));
return;
} else if (!verify_email || !*verify_email) {
DEBUG_ANCHOR("NOTICE: Trust anchor fetching explicitely "
"disabled by empty verify email address\n");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Trust anchor verification explicitely "
"disabled by empty verify email\n");
return;
} else if (!_getdns_context_can_write_appdata(context)) {
DEBUG_ANCHOR("NOTICE %s(): Not fetching TA, because "
"non writeable appdata directory\n", __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "Not fetching TA, because "
"non writeable appdata directory\n");
return;
}
DEBUG_ANCHOR("Hostname: %s\n", tas_hostname);
@ -1561,34 +1630,36 @@ void _getdns_start_fetching_ta(
loop == &context->sync_eventloop.loop ? "" : "a");
scheduled = 0;
#if 1
context->a.state = TAS_LOOKUP_ADDRESSES;
if ((r = _getdns_general_loop(context, loop,
tas_hostname, GETDNS_RRTYPE_A,
no_dnssec_checking_disabled_opportunistic,
context, &context->a.req, NULL, _tas_hostname_lookup_cb))) {
DEBUG_ANCHOR("Error scheduling A lookup for %s: %s\n"
, tas_hostname, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "Error scheduling A lookup for %s: %s\n"
, tas_hostname, getdns_get_errorstr_by_id(r));
} else
scheduled += 1;
#endif
#if 1
context->aaaa.state = TAS_LOOKUP_ADDRESSES;
if ((r = _getdns_general_loop(context, loop,
tas_hostname, GETDNS_RRTYPE_AAAA,
no_dnssec_checking_disabled_opportunistic,
context, &context->aaaa.req, NULL, _tas_hostname_lookup_cb))) {
DEBUG_ANCHOR("Error scheduling AAAA lookup for %s: %s\n"
, tas_hostname, getdns_get_errorstr_by_id(r));
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "Error scheduling AAAA lookup for %s: %s\n"
, tas_hostname, getdns_get_errorstr_by_id(r));
} else
scheduled += 1;
#endif
if (!scheduled) {
DEBUG_ANCHOR("Fatal error fetching trust anchor: Unable to "
"schedule address requests for %s\n"
, tas_hostname);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_WARNING
, "Error scheduling address lookups for %s\n"
, tas_hostname);
context->trust_anchors_source = GETDNS_TASRC_FAILED;
if (now_ms) {
if (*now_ms == 0) *now_ms = _getdns_get_now_ms();
@ -1713,7 +1784,10 @@ static void _getdns_context_read_root_ksk(getdns_context *context)
buf_sz *= 2;
}
if (!(buf = GETDNS_XMALLOC(context->mf, uint8_t, buf_sz))) {
DEBUG_ANCHOR("ERROR %s(): Memory error\n", __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error allocating memory to read "
"root.key\n");
break;;
}
ptr = buf;
@ -1798,8 +1872,10 @@ _getdns_context_update_root_ksk(
break;
}
if (str_buf != str_spc) {
DEBUG_ANCHOR("ERROR %s(): Buffer size determination "
"error\n", __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error determining buffer size for root "
"KSK\n");
if (str_buf)
GETDNS_FREE(context->mf, str_buf);
@ -1807,11 +1883,13 @@ _getdns_context_update_root_ksk(
}
if (!(str_pos = str_buf = GETDNS_XMALLOC( context->mf, char,
(str_sz = sizeof(str_spc) - remaining) + 1))) {
DEBUG_ANCHOR("ERROR %s(): Memory error\n", __FUNC__);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error allocating memory to read "
"root KSK\n");
return;
}
remaining = str_sz + 1;
DEBUG_ANCHOR("Retrying with buf size: %d\n", remaining);
};
/* Write presentation format DNSKEY rrset to "root.key" file */
@ -1886,17 +1964,21 @@ _getdns_context_update_root_ksk(
break;
}
if (!ta) {
DEBUG_ANCHOR("NOTICE %s(): Key with id %d "
"*not* found in TA.\n"
"\"root-anchors.xml\" need "
"updating.\n", __FUNC__
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR
, GETDNS_LOG_NOTICE
, "Key with id %d not found in TA; "
"\"root-anchors.xml\" needs to be "
"updated.\n"
, context->root_ksk.ids[i]);
context->trust_anchors_source =
GETDNS_TASRC_XML_UPDATE;
break;
}
DEBUG_ANCHOR("DEBUG %s(): Key with id %d found in TA\n"
, __FUNC__, context->root_ksk.ids[i]);
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_DEBUG
, "Key with id %d found in TA\n"
, context->root_ksk.ids[i]);
}
}
if (str_buf && str_buf != str_spc)

View File

@ -5148,12 +5148,15 @@ static size_t _getdns_get_appdata(const getdns_context *context, char *path)
} else if (! SUCCEEDED(SHGetFolderPath(NULL,
CSIDL_APPDATA | CSIDL_FLAG_CREATE, NULL, 0, path)))
DEBUG_ANCHOR("ERROR %s(): Could not get %%AppData%% directory\n"
, __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_NOTICE
, "Could not get %%AppData%% directory\n");
else if ((len = strlen(path)) + sizeof(APPDATA_SUBDIR) + 2 >= _GETDNS_PATH_MAX)
DEBUG_ANCHOR("ERROR %s(): Home path too long for appdata\n"
, __FUNC__);
else if ((len = strlen(path))
+ sizeof(APPDATA_SUBDIR) + 2 >= _GETDNS_PATH_MAX)
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Path name for appdata directory too long\n");
#else
# define SLASHTOK '/'
# define APPDATA_SUBDIR ".getdns"
@ -5165,12 +5168,14 @@ static size_t _getdns_get_appdata(const getdns_context *context, char *path)
len = strlen(path);
} else if (!(home = p ? p->pw_dir : getenv("HOME")))
DEBUG_ANCHOR("ERROR %s(): Could not get home directory\n"
, __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_NOTICE
, "Unable to determine home directory location\n");
else if ((len = strlen(home)) + sizeof(APPDATA_SUBDIR) + 2 >= _GETDNS_PATH_MAX)
DEBUG_ANCHOR("ERROR %s(): Home path too long for appdata\n"
, __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Path name for appdata directory too long\n");
else if (!strcpy(path, home))
; /* strcpy returns path always */
@ -5195,8 +5200,10 @@ static size_t _getdns_get_appdata(const getdns_context *context, char *path)
mkdir(path, 0755)
#endif
&& errno != EEXIST)
DEBUG_ANCHOR("ERROR %s(): Could not mkdir %s: %s\n"
, __FUNC__, path, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "mkdir(\"%s\") failed: %s\n"
, path, _getdns_errnostr());
else {
path[len++] = SLASHTOK;
path[len ] = '\0';
@ -5214,26 +5221,20 @@ FILE *_getdns_context_get_priv_fp(
FILE *f = NULL;
size_t len = _getdns_get_appdata(context, path);
(void) context;
/*
* Commented out to enable fallback to current directory
*
* if (!(len = _getdns_get_appdata(context, path)))
* DEBUG_ANCHOR("ERROR %s(): Could nog get application data path\n"
* , __FUNC__);
*
* else
*/
if (len + strlen(fn) >= sizeof(path))
DEBUG_ANCHOR("ERROR %s(): Application data too long\n", __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Path name for appdata directory too long\n");
else if (!strcpy(path + len, fn))
; /* strcpy returns path + len always */
else if (!(f = fopen(path, "r")))
DEBUG_ANCHOR("ERROR %s(): Opening \"%s\": %s\n"
, __FUNC__, path, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Error opening \"%s\": %s\n"
, path, _getdns_errnostr());
return f;
}
@ -5251,20 +5252,26 @@ uint8_t *_getdns_context_get_priv_file(const getdns_context *context,
return buf;
}
else if (fseek(f, 0, SEEK_END) < 0)
DEBUG_ANCHOR("ERROR %s(): Determining size of \"%s\": %s\n"
, __FUNC__, fn, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error determining size of \"%s\": %s\n"
, fn, _getdns_errnostr());
else if (!(buf = GETDNS_XMALLOC(
context->mf, uint8_t, (buf_len = ftell(f) + 1))))
DEBUG_ANCHOR("ERROR %s(): Allocating %d memory for \"%s\"\n"
, __FUNC__, (int)buf_len, fn);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error allocating %d bytes of memory for \"%s\"\n"
, (int)buf_len, fn);
else {
rewind(f);
if ((*file_sz = fread(buf, 1, buf_len, f)) >= buf_len || !feof(f)) {
GETDNS_FREE(context->mf, buf);
DEBUG_ANCHOR("ERROR %s(): Reading \"%s\": %s\n"
, __FUNC__, fn, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error reding \"%s\": %s\n"
, fn, _getdns_errnostr());
}
else {
buf[*file_sz] = 0;
@ -5286,46 +5293,51 @@ int _getdns_context_write_priv_file(getdns_context *context,
FILE *f = NULL;
size_t len = _getdns_get_appdata(context, path);
/*
* Commented out to enable fallback to current directory
*
* if (!(len = _getdns_get_appdata(context, path)))
* DEBUG_ANCHOR("ERROR %s(): Could nog get application data path\n"
* , __FUNC__);
*
* else
*/
if (len + 6 >= sizeof(tmpfn)
|| len + strlen(fn) >= sizeof(path))
DEBUG_ANCHOR("ERROR %s(): Application data too long\n", __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Application data filename \"%s\" too long\n"
, fn);
else if (snprintf(tmpfn, sizeof(tmpfn), "%sXXXXXX", path) < 0)
DEBUG_ANCHOR("ERROR %s(): Creating temporary filename template: \"%s\"\n"
, __FUNC__, tmpfn);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error creating temporary file template \"%s\"\n"
, tmpfn);
else if (!strcpy(path + len, fn))
; /* strcpy returns path + len always */
else if ((fd = mkstemp(tmpfn)) < 0)
DEBUG_ANCHOR("ERROR %s(): Creating temporary file \"%s\": %s\n"
, __FUNC__, tmpfn, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_INFO
, "Could not create temporary file \"%s\": %s\n"
, tmpfn, _getdns_errnostr());
else if (!(f = fdopen(fd, "w")))
DEBUG_ANCHOR("ERROR %s(): Opening temporary file: %s\n"
, __FUNC__, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error opening temporary file \"%s\": %s\n"
, tmpfn, _getdns_errnostr());
else if (fwrite(content->data, 1, content->size, f) < content->size)
DEBUG_ANCHOR("ERROR %s(): Writing temporary file: %s\n"
, __FUNC__, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error writing to temporary file \"%s\": %s\n"
, tmpfn, _getdns_errnostr());
else if (fclose(f) < 0)
DEBUG_ANCHOR("ERROR %s(): Closing temporary file: %s\n"
, __FUNC__, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error closing temporary file \"%s\": %s\n"
, tmpfn, _getdns_errnostr());
else if (rename(tmpfn, path) < 0)
DEBUG_ANCHOR("ERROR %s(): Renaming temporary file: %s\n"
, __FUNC__, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error renaming temporary file \"%s\" to \"%s\""
": %s\n", tmpfn, path, _getdns_errnostr());
else {
context->can_write_appdata = PROP_ABLE;
return 1;
@ -5359,26 +5371,21 @@ int _getdns_context_can_write_appdata(getdns_context *context)
return 0;
len = _getdns_get_appdata(context, path);
/*
* Commented out to enable fallback to current directory
*
*
* if (!(len = _getdns_get_appdata(context, path)))
* DEBUG_ANCHOR("ERROR %s(): Could not get application data path\n"
* , __FUNC__);
*
* else
*/
if (len + strlen(test_fn) >= sizeof(path))
DEBUG_ANCHOR("ERROR %s(): Application data too long\n", __FUNC__);
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Application data too long \"%s\" + \"%s\"\n"
, path, test_fn);
else if (!strcpy(path + len, test_fn))
; /* strcpy returns path + len always */
else if (unlink(path) < 0)
DEBUG_ANCHOR("ERROR %s(): Unlinking write test file \"%s\": %s\n"
, __FUNC__, path, strerror(errno));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Error unlinking write test file: \"%s\": %s\n"
, path, _getdns_errnostr());
return 1;
}
@ -5537,26 +5544,36 @@ getdns_context *_getdns_context_get_sys_ctxt(
&context->sys_ctxt, 1, context->mf.mf_arg,
context->mf.mf.ext.malloc, context->mf.mf.ext.realloc,
context->mf.mf.ext.free)))
DEBUG_ANCHOR("Could not create system context: %s\n"
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Could not create system context: %s\n"
, getdns_get_errorstr_by_id(r));
#ifndef USE_WINSOCK
else if (*context->fchg_resolvconf.fn &&
(r = getdns_context_set_resolvconf(
context->sys_ctxt, context->fchg_resolvconf.fn)))
DEBUG_ANCHOR("Could initialize system context with resolvconf "
"\"%s\": %s\n", context->fchg_resolvconf.fn
, getdns_get_errorstr_by_id(r));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Could not initialize system context with "
"resolvconf \"%s\": %s\n"
, context->fchg_resolvconf.fn
, getdns_get_errorstr_by_id(r));
#endif
else if (*context->fchg_hosts.fn &&
(r = getdns_context_set_hosts(
context->sys_ctxt, context->fchg_hosts.fn)))
DEBUG_ANCHOR("Could initialize system context with hosts "
"\"%s\": %s\n", context->fchg_resolvconf.fn
, getdns_get_errorstr_by_id(r));
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Could not initialize system context with "
"hosts \"%s\": %s\n"
, context->fchg_hosts.fn
, getdns_get_errorstr_by_id(r));
else if ((r = getdns_context_set_eventloop(
context->sys_ctxt, loop)))
DEBUG_ANCHOR("Could not configure %ssynchronous loop "
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Could not configure %ssynchronous loop "
"with system context: %s\n"
, ( loop == &context->sync_eventloop.loop
? "" : "a" )
@ -5564,7 +5581,9 @@ getdns_context *_getdns_context_get_sys_ctxt(
else if ((r = getdns_context_set_resolution_type(
context->sys_ctxt, GETDNS_RESOLUTION_STUB)))
DEBUG_ANCHOR("Could not configure system context for "
_getdns_log(&context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_ERR
, "Could not configure system context for "
"stub resolver: %s\n"
, getdns_get_errorstr_by_id(r));
else

View File

@ -3289,7 +3289,6 @@ static void check_chain_complete(chain_head *chain)
} else if (_getdns_bogus(dnsreq)) {
_getdns_rrsig_iter rrsig_spc;
DEBUG_ANCHOR("Request was bogus!\n");
if ((head = chain) && (node = _to_the_root(head->parent))
/* The root DNSKEY rrset */
@ -3302,7 +3301,9 @@ static void check_chain_complete(chain_head *chain)
&& _getdns_rrsig_iter_init(&rrsig_spc, &node->dnskey)
){
DEBUG_ANCHOR("root DNSKEY set was bogus!\n");
_getdns_log( &context->log
, GETDNS_LOG_SYS_ANCHOR, GETDNS_LOG_NOTICE
, "root DNSKEY set was bogus!\n");
if (!dnsreq->waiting_for_ta) {
uint64_t now_ms = 0;

View File

@ -243,7 +243,6 @@ _getdns_check_dns_req_complete(getdns_dns_req *dns_req)
#if defined(REQ_DEBUG) && REQ_DEBUG
debug_req("getting validation chain for ", *dns_req->netreqs);
#endif
DEBUG_ANCHOR("Valchain lookup\n");
_getdns_get_validation_chain(dns_req);
} else
_getdns_call_user_callback(

View File

@ -565,6 +565,9 @@ typedef enum getdns_loglevel_type {
#define GETDNS_LOG_SYS_RECURSING_TEXT "Log messages about recursive resolving"
#define GETDNS_LOG_SYS_RESOLVING 0x6000
#define GETDNS_LOG_SYS_RESOLVING_TEXT "Log messages about resolving"
#define GETDNS_LOG_SYS_ANCHOR 0x8000
#define GETDNS_LOG_SYS_ANCHOR_TEXT "Log messages about fetching trust anchors"
typedef void (*getdns_logfunc_type) (void *userarg, uint64_t log_systems,