upstream/unbound
1
0
Fork 0
mirror of https://github.com/NLnetLabs/unbound.git synced 2026-01-05 14:29:37 -05:00
Code Issues Projects Releases Packages Wiki Activity Actions

- verbose information about auth zone lookup process, also lookup

Browse source 
start, timeout and fail.


git-svn-id: file:///svn/unbound/trunk@5150 be551aaa-1e26-0410-a405-d3ace91eadb9
This commit is contained in:
Wouter Wijngaards 2019-04-08 12:42:09 +00:00
parent 2b47ca080e
commit c26fc84945
2 changed files with 112 additions and 11 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

2
doc/Changelog
View file

@ -1,5 +1,7 @@
8 April 2019: Wouter
- Fix to use event_assign with libevent for thread-safety.
- verbose information about auth zone lookup process, also lookup
start, timeout and fail.
5 April 2019: Wouter
- Fix to reinit event structure for accepted TCP (and TLS) sockets.

121
services/authzone.c
View file

@ -5091,13 +5091,19 @@ xfr_transfer_init_fetch(struct auth_xfer* xfr, struct module_env* env)
&addr, addrlen, AUTH_TRANSFER_TIMEOUT, master->ssl,
master->host, master->file);
if(!xfr->task_transfer->cp) {
char zname[255+1];
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "cannot create http cp "
"connection for %s to %s", zname,
master->host);
"connection for %s to %s", zname, as);
return 0;
}
if(verbosity >= VERB_ALGO) {
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "auth zone %s transfer next HTTP fetch from %s started", zname, as);
}
return 1;
}
@ -5113,12 +5119,20 @@ xfr_transfer_init_fetch(struct auth_xfer* xfr, struct module_env* env)
auth_xfer_transfer_tcp_callback, xfr, &addr, addrlen,
env->scratch_buffer, AUTH_TRANSFER_TIMEOUT);
if(!xfr->task_transfer->cp) {
char zname[255+1];
dname_str(xfr->name, zname);
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "cannot create tcp cp connection for "
"xfr %s to %s", zname, master->host);
"xfr %s to %s", zname, as);
return 0;
}
if(verbosity >= VERB_ALGO) {
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "auth zone %s transfer next %s fetch from %s started", zname,
(xfr->task_transfer->on_ixfr?"IXFR":"AXFR"), as);
}
return 1;
}
@ -5136,6 +5150,11 @@ xfr_transfer_nexttarget_or_end(struct auth_xfer* xfr, struct module_env* env)
* and we may then get an instant cache response,
* and that calls the callback just like a full
* lookup and lookup failures also call callback */
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s transfer next target lookup", zname);
}
lock_basic_unlock(&xfr->lock);
return;
}
@ -5154,6 +5173,11 @@ xfr_transfer_nexttarget_or_end(struct auth_xfer* xfr, struct module_env* env)
/* failed to fetch, next master */
xfr_transfer_nextmaster(xfr);
}
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s transfer failed, wait", zname);
}
/* we failed to fetch the zone, move to wait task
* use the shorter retry timeout */
@ -5251,7 +5275,25 @@ void auth_xfer_transfer_lookup_callback(void* arg, int rcode, sldns_buffer* buf,
if(answer) {
xfr_master_add_addrs(xfr->task_transfer->
lookup_target, answer, wanted_qtype);
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s transfer lookup has nodata", zname, xfr->task_transfer->lookup_target->host, (xfr->task_transfer->lookup_aaaa?"AAAA":"A"));
}
}
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s transfer lookup has no answer", zname, xfr->task_transfer->lookup_target->host, (xfr->task_transfer->lookup_aaaa?"AAAA":"A"));
}
}
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s transfer lookup failed", zname, xfr->task_transfer->lookup_target->host, (xfr->task_transfer->lookup_aaaa?"AAAA":"A"));
}
}
if(xfr->task_transfer->lookup_target->list &&
@ -5862,10 +5904,11 @@ xfr_probe_send_probe(struct auth_xfer* xfr, struct module_env* env,
xfr->task_probe->cp = outnet_comm_point_for_udp(env->outnet,
auth_xfer_probe_udp_callback, xfr, &addr, addrlen);
if(!xfr->task_probe->cp) {
char zname[255+1];
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "cannot create udp cp for "
"probe %s to %s", zname, master->host);
"probe %s to %s", zname, as);
return 0;
}
}
@ -5881,12 +5924,20 @@ xfr_probe_send_probe(struct auth_xfer* xfr, struct module_env* env,
/* send udp packet */
if(!comm_point_send_udp_msg(xfr->task_probe->cp, env->scratch_buffer,
(struct sockaddr*)&addr, addrlen)) {
char zname[255+1];
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "failed to send soa probe for %s to %s",
zname, master->host);
zname, as);
return 0;
}
if(verbosity >= VERB_ALGO) {
char zname[255+1], as[256];
dname_str(xfr->name, zname);
addr_to_str(&addr, addrlen, as, sizeof(as));
verbose(VERB_ALGO, "auth zone %s soa probe sent to %s", zname,
as);
}
xfr->task_probe->timeout = timeout;
#ifndef S_SPLINT_S
t.tv_sec = timeout/1000;
@ -5912,6 +5963,12 @@ auth_xfer_probe_timer_callback(void* arg)
}
if(xfr->task_probe->timeout <= AUTH_PROBE_TIMEOUT_STOP) {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s soa probe timeout",
zname);
}
/* try again with bigger timeout */
if(xfr_probe_send_probe(xfr, env, xfr->task_probe->timeout*2)) {
lock_basic_unlock(&xfr->lock);
@ -6098,6 +6155,11 @@ xfr_probe_send_or_end(struct auth_xfer* xfr, struct module_env* env)
* and we may then get an instant cache response,
* and that calls the callback just like a full
* lookup and lookup failures also call callback */
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s probe next target lookup", zname);
}
lock_basic_unlock(&xfr->lock);
return;
}
@ -6106,9 +6168,19 @@ xfr_probe_send_or_end(struct auth_xfer* xfr, struct module_env* env)
/* probe of list has ended. Create or refresh the list of of
* allow_notify addrs */
probe_copy_masters_for_allow_notify(xfr);
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s probe: notify addrs updated", zname);
}
if(xfr->task_probe->only_lookup) {
/* only wanted lookups for copy, stop probe and start wait */
xfr->task_probe->only_lookup = 0;
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s probe: finished only_lookup", zname);
}
xfr_probe_disown(xfr);
if(xfr->task_nextprobe->worker == NULL)
xfr_set_timeout(xfr, env, 0, 0);
@ -6130,13 +6202,22 @@ xfr_probe_send_or_end(struct auth_xfer* xfr, struct module_env* env)
/* done with probe sequence, wait */
if(xfr->task_probe->have_new_lease) {
/* if zone not updated, start the wait timer again */
verbose(VERB_ALGO, "auth_zone unchanged, new lease, wait");
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth_zone %s unchanged, new lease, wait", zname);
}
xfr_probe_disown(xfr);
if(xfr->have_zone)
xfr->lease_time = *env->now;
if(xfr->task_nextprobe->worker == NULL)
xfr_set_timeout(xfr, env, 0, 0);
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s soa probe failed, wait to retry", zname);
}
/* we failed to send this as well, move to the wait task,
* use the shorter retry timeout */
xfr_probe_disown(xfr);
@ -6181,7 +6262,25 @@ void auth_xfer_probe_lookup_callback(void* arg, int rcode, sldns_buffer* buf,
if(answer) {
xfr_master_add_addrs(xfr->task_probe->
lookup_target, answer, wanted_qtype);
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s probe lookup has nodata", zname, xfr->task_probe->lookup_target->host, (xfr->task_probe->lookup_aaaa?"AAAA":"A"));
}
}
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s probe lookup has no address", zname, xfr->task_probe->lookup_target->host, (xfr->task_probe->lookup_aaaa?"AAAA":"A"));
}
}
} else {
if(verbosity >= VERB_ALGO) {
char zname[255+1];
dname_str(xfr->name, zname);
verbose(VERB_ALGO, "auth zone %s host %s type %s probe lookup failed", zname, xfr->task_probe->lookup_target->host, (xfr->task_probe->lookup_aaaa?"AAAA":"A"));
}
}
if(xfr->task_probe->lookup_target->list &&