From 7f4a61e6fc6285a986b57cf49d7df080c029d070 Mon Sep 17 00:00:00 2001 From: Yorgos Thessalonikefs Date: Tue, 24 Sep 2024 12:21:03 +0200 Subject: [PATCH 1/5] - Attempt to further fix doh_downstream_buffer_size.tdir flakiness. --- doc/Changelog | 3 +++ .../doh_downstream_buffer_size.test | 2 +- 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/doc/Changelog b/doc/Changelog index 75dfdc629..afc66f846 100644 --- a/doc/Changelog +++ b/doc/Changelog @@ -1,3 +1,6 @@ +24 September 2024: Yorgos + - Attempt to further fix doh_downstream_buffer_size.tdir flakiness. + 23 September 2024: Wouter - Fix dns64 with prefetch that the prefetch is stored in cache. diff --git a/testdata/doh_downstream_buffer_size.tdir/doh_downstream_buffer_size.test b/testdata/doh_downstream_buffer_size.tdir/doh_downstream_buffer_size.test index 45bde6564..00389fde2 100644 --- a/testdata/doh_downstream_buffer_size.tdir/doh_downstream_buffer_size.test +++ b/testdata/doh_downstream_buffer_size.tdir/doh_downstream_buffer_size.test @@ -33,7 +33,7 @@ echo "num answers $num and num write events $nummodew" if [ $num -eq 8 ]; then echo "content OK" else - if [ "(" $num -eq 9 -o $num -eq 10 ")" -a $nummodew -eq 2 ]; then + if [ "(" $num -eq 9 -o $num -eq 10 ")" -a "(" $nummodew -eq 2 -o $nummodew -eq 3 ")" ]; then echo "skip buffer emptied event" else echo "result contents not OK" From 24ebca7df6039ddcff52884c19db846024d162a4 Mon Sep 17 00:00:00 2001 From: Yorgos Thessalonikefs Date: Tue, 24 Sep 2024 15:10:21 +0200 Subject: [PATCH 2/5] - More clear text for prefetch and minimal-responses in the unbound.conf man page. --- doc/Changelog | 2 ++ doc/unbound.conf.5.in | 20 +++++++++++--------- 2 files changed, 13 insertions(+), 9 deletions(-) diff --git a/doc/Changelog b/doc/Changelog index afc66f846..4c32cc38a 100644 --- a/doc/Changelog +++ b/doc/Changelog @@ -1,5 +1,7 @@ 24 September 2024: Yorgos - Attempt to further fix doh_downstream_buffer_size.tdir flakiness. + - More clear text for prefetch and minimal-responses in the + unbound.conf man page. 23 September 2024: Wouter - Fix dns64 with prefetch that the prefetch is stored in cache. diff --git a/doc/unbound.conf.5.in b/doc/unbound.conf.5.in index f4cf81778..d9c7f249a 100644 --- a/doc/unbound.conf.5.in +++ b/doc/unbound.conf.5.in @@ -1176,10 +1176,11 @@ IP6 ::1 and IP4 127.0.0.1/8. If no, then localhost can be used to send queries to. Default is yes. .TP .B prefetch: \fI -If yes, message cache elements are prefetched before they expire to -keep the cache up to date. Default is no. Turning it on gives about -10 percent more traffic and load on the machine, but popular items do -not expire from the cache. +If yes, cache hits on message cache elements that are on their last 10 percent +of their TTL value trigger a prefetch to keep the cache up to date. +Default is no. +Turning it on gives about 10 percent more traffic and load on the machine, but +popular items do not expire from the cache. .TP .B prefetch\-key: \fI If yes, fetch the DNSKEYs earlier in the validation process, when a DS @@ -1199,12 +1200,13 @@ from the query ID, for speed and thread safety). Default is yes. .B minimal-responses: \fI If yes, Unbound does not insert authority/additional sections into response messages when those sections are not required. This reduces response -size significantly, and may avoid TCP fallback for some responses. -This may cause a slight speedup. The default is yes, even though the DNS +size significantly, and may avoid TCP fallback for some responses which may +cause a slight speedup. The default is yes, even though the DNS protocol RFCs mandate these sections, and the additional content could -be of use and save roundtrips for clients. Because they are not used, -and the saved roundtrips are easier saved with prefetch, whilst this is -faster. +save roundtrips for clients that use the additional content. +However these sections are hardly used by clients. +Enabling prefetch can benefit clients that need the additional content +by trying to keep that content fresh in the cache. .TP .B disable-dnssec-lame-check: \fI If true, disables the DNSSEC lameness check in the iterator. This check From 2e398d51ba72ca824473b6528a43f53784108d67 Mon Sep 17 00:00:00 2001 From: Yorgos Thessalonikefs Date: Tue, 24 Sep 2024 16:47:04 +0200 Subject: [PATCH 3/5] Fix cache update when serve expired is used (#1143) - Fix cache update when serve expired is used in order to not evict still usable expired records. Modules are forbidden to update the cache if their answer is DNSSEC unchecked or bogus and a valid (expired) entry already exists. Bogus replies from the validator are also discarded in favor of existing (expired) valid replies. - serve-expired-ttl-reset should try to keep expired records in the cache in case they are reset. --- cachedb/cachedb.c | 2 - daemon/remote.c | 4 + daemon/worker.c | 18 +- dns64/dns64.c | 1 + iterator/iterator.c | 23 +- services/cache/dns.c | 51 ++- services/cache/rrset.c | 10 +- services/mesh.c | 13 +- services/mesh.h | 3 +- services/rpz.c | 4 + testcode/unitmain.c | 2 +- testdata/serve_expired_cached_servfail.rpl | 2 +- .../serve_expired_cached_servfail_refresh.rpl | 2 +- .../serve_expired_client_timeout_servfail.rpl | 83 ++++- ...serve_expired_client_timeout_val_bogus.rpl | 317 ++++++++++++++++++ ...client_timeout_val_insecure_delegation.rpl | 247 ++++++++++++++ testdata/serve_expired_ttl_reset.rpl | 102 ++++++ testdata/serve_expired_val_bogus.rpl | 316 +++++++++++++++++ util/config_file.c | 5 +- util/data/msgparse.h | 2 + util/data/msgreply.c | 47 ++- util/data/msgreply.h | 39 ++- util/module.h | 6 +- validator/validator.c | 52 ++- 24 files changed, 1282 insertions(+), 69 deletions(-) create mode 100644 testdata/serve_expired_client_timeout_val_bogus.rpl create mode 100644 testdata/serve_expired_client_timeout_val_insecure_delegation.rpl create mode 100644 testdata/serve_expired_ttl_reset.rpl create mode 100644 testdata/serve_expired_val_bogus.rpl diff --git a/cachedb/cachedb.c b/cachedb/cachedb.c index 7a07b9976..cf5143ee3 100644 --- a/cachedb/cachedb.c +++ b/cachedb/cachedb.c @@ -828,8 +828,6 @@ cachedb_handle_query(struct module_qstate* qstate, /* In case we have expired data but there is a client timer for expired * answers, pass execution to next module in order to try updating the * data first. - * TODO: this needs revisit. The expired data stored from cachedb has - * 0 TTL which is picked up by iterator later when looking in the cache. */ if(qstate->env->cfg->serve_expired && msg_expired) { qstate->return_msg = NULL; diff --git a/daemon/remote.c b/daemon/remote.c index 855b1f963..5af03328e 100644 --- a/daemon/remote.c +++ b/daemon/remote.c @@ -1953,6 +1953,8 @@ bogus_del_msg(struct lruhash_entry* e, void* arg) struct reply_info* d = (struct reply_info*)e->data; if(d->security == sec_status_bogus) { d->ttl = inf->expired; + d->prefetch_ttl = inf->expired; + d->serve_expired_ttl = inf->expired; inf->num_msgs++; #ifdef USE_CACHEDB if(inf->remcachedb && inf->worker->env.cachedb_enabled) @@ -2035,6 +2037,8 @@ negative_del_msg(struct lruhash_entry* e, void* arg) * or NOERROR rcode with ANCOUNT==0: a NODATA answer */ if(FLAGS_GET_RCODE(d->flags) != 0 || d->an_numrrsets == 0) { d->ttl = inf->expired; + d->prefetch_ttl = inf->expired; + d->serve_expired_ttl = inf->expired; inf->num_msgs++; #ifdef USE_CACHEDB if(inf->remcachedb && inf->worker->env.cachedb_enabled) diff --git a/daemon/worker.c b/daemon/worker.c index 5e6b2a656..fe105eb7b 100644 --- a/daemon/worker.c +++ b/daemon/worker.c @@ -661,22 +661,18 @@ answer_from_cache(struct worker* worker, struct query_info* qinfo, if(rep->ttl < timenow) { /* Check if we need to serve expired now */ if(worker->env.cfg->serve_expired && - !worker->env.cfg->serve_expired_client_timeout + /* if serve-expired-client-timeout is set, serve + * an expired record without attempting recursion + * if the serve_expired_norec_ttl is set for the record + * as we know that recursion is currently failing. */ + (!worker->env.cfg->serve_expired_client_timeout || + timenow < rep->serve_expired_norec_ttl) #ifdef USE_CACHEDB && !(worker->env.cachedb_enabled && worker->env.cfg->cachedb_check_when_serve_expired) #endif ) { - if(worker->env.cfg->serve_expired_ttl && - rep->serve_expired_ttl < timenow) - return 0; - /* Ignore expired failure answers */ - if(FLAGS_GET_RCODE(rep->flags) != - LDNS_RCODE_NOERROR && - FLAGS_GET_RCODE(rep->flags) != - LDNS_RCODE_NXDOMAIN && - FLAGS_GET_RCODE(rep->flags) != - LDNS_RCODE_YXDOMAIN) + if(!reply_info_can_answer_expired(rep, timenow)) return 0; if(!rrset_array_lock(rep->ref, rep->rrset_count, 0)) return 0; diff --git a/dns64/dns64.c b/dns64/dns64.c index 49718e3d8..0db174ba9 100644 --- a/dns64/dns64.c +++ b/dns64/dns64.c @@ -847,6 +847,7 @@ dns64_adjust_a(int id, struct module_qstate* super, struct module_qstate* qstate */ cp = construct_reply_info_base(super->region, rep->flags, rep->qdcount, rep->ttl, rep->prefetch_ttl, rep->serve_expired_ttl, + rep->serve_expired_norec_ttl, rep->an_numrrsets, rep->ns_numrrsets, rep->ar_numrrsets, rep->rrset_count, rep->security, LDNS_EDE_NONE); if(!cp) diff --git a/iterator/iterator.c b/iterator/iterator.c index d566a7998..0b66db8a6 100644 --- a/iterator/iterator.c +++ b/iterator/iterator.c @@ -322,16 +322,21 @@ error_response_cache(struct module_qstate* qstate, int id, int rcode) qstate->qinfo.qname, qstate->qinfo.qname_len, qstate->qinfo.qtype, qstate->qinfo.qclass, qstate->query_flags, 0, - qstate->env->cfg->serve_expired_ttl_reset)) != NULL) { + qstate->env->cfg->serve_expired)) != NULL) { struct reply_info* rep = (struct reply_info*)msg->entry.data; - if(qstate->env->cfg->serve_expired && - qstate->env->cfg->serve_expired_ttl_reset && rep && - *qstate->env->now + qstate->env->cfg->serve_expired_ttl - > rep->serve_expired_ttl) { - verbose(VERB_ALGO, "reset serve-expired-ttl for " + if(qstate->env->cfg->serve_expired && rep) { + if(qstate->env->cfg->serve_expired_ttl_reset && + *qstate->env->now + qstate->env->cfg->serve_expired_ttl + > rep->serve_expired_ttl) { + verbose(VERB_ALGO, "reset serve-expired-ttl for " + "response in cache"); + rep->serve_expired_ttl = *qstate->env->now + + qstate->env->cfg->serve_expired_ttl; + } + verbose(VERB_ALGO, "set serve-expired-norec-ttl for " "response in cache"); - rep->serve_expired_ttl = *qstate->env->now + - qstate->env->cfg->serve_expired_ttl; + rep->serve_expired_norec_ttl = NORR_TTL + + *qstate->env->now; } if(rep && (FLAGS_GET_RCODE(rep->flags) == LDNS_RCODE_NOERROR || @@ -4046,6 +4051,8 @@ processClassResponse(struct module_qstate* qstate, int id, to->rep->prefetch_ttl = from->rep->prefetch_ttl; if(from->rep->serve_expired_ttl < to->rep->serve_expired_ttl) to->rep->serve_expired_ttl = from->rep->serve_expired_ttl; + if(from->rep->serve_expired_norec_ttl < to->rep->serve_expired_norec_ttl) + to->rep->serve_expired_norec_ttl = from->rep->serve_expired_norec_ttl; } /* are we done? */ foriq->num_current_queries --; diff --git a/services/cache/dns.c b/services/cache/dns.c index dd8df4554..8a08d3a30 100644 --- a/services/cache/dns.c +++ b/services/cache/dns.c @@ -162,7 +162,7 @@ dns_cache_store_msg(struct module_env* env, struct query_info* qinfo, size_t i; /* store RRsets */ - for(i=0; irrset_count; i++) { + for(i=0; irrset_count; i++) { rep->ref[i].key = rep->rrsets[i]; rep->ref[i].id = rep->rrsets[i]->id; } @@ -197,6 +197,7 @@ dns_cache_store_msg(struct module_env* env, struct query_info* qinfo, reply_info_sortref(rep); if(!(e = query_info_entrysetup(qinfo, rep, hash))) { log_err("store_msg: malloc failed"); + reply_info_delete(rep, NULL); return; } slabhash_insert(env->msg_cache, hash, &e->entry, rep, env->alloc); @@ -607,22 +608,8 @@ tomsg(struct module_env* env, struct query_info* q, struct reply_info* r, time_t now_control = now; if(now > r->ttl) { /* Check if we are allowed to serve expired */ - if(allow_expired) { - if(env->cfg->serve_expired_ttl && - r->serve_expired_ttl < now) { - return NULL; - } - /* Ignore expired failure answers */ - if(FLAGS_GET_RCODE(r->flags) != - LDNS_RCODE_NOERROR && - FLAGS_GET_RCODE(r->flags) != - LDNS_RCODE_NXDOMAIN && - FLAGS_GET_RCODE(r->flags) != - LDNS_RCODE_YXDOMAIN) - return 0; - } else { + if(!allow_expired || !reply_info_can_answer_expired(r, now)) return NULL; - } /* Change the current time so we can pass the below TTL checks when * serving expired data. */ now_control = r->ttl - env->cfg->serve_expired_reply_ttl; @@ -641,6 +628,7 @@ tomsg(struct module_env* env, struct query_info* q, struct reply_info* r, else msg->rep->prefetch_ttl = PREFETCH_TTL_CALC(msg->rep->ttl); msg->rep->serve_expired_ttl = msg->rep->ttl + SERVE_EXPIRED_TTL; + msg->rep->serve_expired_norec_ttl = 0; msg->rep->security = r->security; msg->rep->an_numrrsets = r->an_numrrsets; msg->rep->ns_numrrsets = r->ns_numrrsets; @@ -724,6 +712,7 @@ rrset_msg(struct ub_packed_rrset_key* rrset, struct regional* region, msg->rep->ttl = d->ttl - now; msg->rep->prefetch_ttl = PREFETCH_TTL_CALC(msg->rep->ttl); msg->rep->serve_expired_ttl = msg->rep->ttl + SERVE_EXPIRED_TTL; + msg->rep->serve_expired_norec_ttl = 0; msg->rep->security = sec_status_unchecked; msg->rep->an_numrrsets = 1; msg->rep->ns_numrrsets = 0; @@ -763,6 +752,7 @@ synth_dname_msg(struct ub_packed_rrset_key* rrset, struct regional* region, msg->rep->ttl = d->ttl - now; msg->rep->prefetch_ttl = PREFETCH_TTL_CALC(msg->rep->ttl); msg->rep->serve_expired_ttl = msg->rep->ttl + SERVE_EXPIRED_TTL; + msg->rep->serve_expired_norec_ttl = 0; msg->rep->security = sec_status_unchecked; msg->rep->an_numrrsets = 1; msg->rep->ns_numrrsets = 0; @@ -1070,6 +1060,35 @@ dns_cache_store(struct module_env* env, struct query_info* msgqinf, struct regional* region, uint32_t flags, time_t qstarttime) { struct reply_info* rep = NULL; + if(SERVE_EXPIRED) { + /* We are serving expired records. Before caching, check if a + * useful expired record exists. */ + struct msgreply_entry* e = msg_cache_lookup(env, + msgqinf->qname, msgqinf->qname_len, msgqinf->qtype, + msgqinf->qclass, flags, 0, 0); + if(e) { + struct reply_info* cached = e->entry.data; + if(cached->ttl < *env->now + && reply_info_could_use_expired(cached, *env->now) + /* If we are validating make sure only + * validating modules can update such messages. + * In that case don't cache it and let a + * subsequent module handle the caching. For + * example, the iterator should not replace an + * expired secure answer with a fresh unchecked + * one and let the validator manage caching. */ + && cached->security != sec_status_bogus + && (env->need_to_validate && + msgrep->security == sec_status_unchecked)) { + verbose(VERB_ALGO, "a validated expired entry " + "could be overwritten, skip caching " + "the new message at this stage"); + lock_rw_unlock(&e->entry.lock); + return 1; + } + lock_rw_unlock(&e->entry.lock); + } + } /* alloc, malloc properly (not in region, like msg is) */ rep = reply_info_copy(msgrep, env->alloc, NULL); if(!rep) diff --git a/services/cache/rrset.c b/services/cache/rrset.c index 2c03214c8..a05ae5a56 100644 --- a/services/cache/rrset.c +++ b/services/cache/rrset.c @@ -128,8 +128,8 @@ need_to_update_rrset(void* nd, void* cd, time_t timenow, int equal, int ns) { struct packed_rrset_data* newd = (struct packed_rrset_data*)nd; struct packed_rrset_data* cached = (struct packed_rrset_data*)cd; - /* o if new data is expired, current data is better */ - if( newd->ttl < timenow && cached->ttl >= timenow) + /* o if new data is expired, cached data is better */ + if( newd->ttl < timenow && timenow <= cached->ttl) return 0; /* o store if rrset has been validated * everything better than bogus data @@ -140,9 +140,9 @@ need_to_update_rrset(void* nd, void* cd, time_t timenow, int equal, int ns) if( cached->security == sec_status_bogus && newd->security != sec_status_bogus && !equal) return 1; - /* o if current RRset is more trustworthy - insert it */ + /* o if new RRset is more trustworthy - insert it */ if( newd->trust > cached->trust ) { - /* if the cached rrset is bogus, and this one equal, + /* if the cached rrset is bogus, and new is equal, * do not update the TTL - let it expire. */ if(equal && cached->ttl >= timenow && cached->security == sec_status_bogus) @@ -155,7 +155,7 @@ need_to_update_rrset(void* nd, void* cd, time_t timenow, int equal, int ns) /* o same trust, but different in data - insert it */ if( newd->trust == cached->trust && !equal ) { /* if this is type NS, do not 'stick' to owner that changes - * the NS RRset, but use the old TTL for the new data, and + * the NS RRset, but use the cached TTL for the new data, and * update to fetch the latest data. ttl is not expired, because * that check was before this one. */ if(ns) { diff --git a/services/mesh.c b/services/mesh.c index 522118844..d512ab3d3 100644 --- a/services/mesh.c +++ b/services/mesh.c @@ -311,7 +311,7 @@ int mesh_make_new_space(struct mesh_area* mesh, sldns_buffer* qbuf) struct dns_msg* mesh_serve_expired_lookup(struct module_qstate* qstate, - struct query_info* lookup_qinfo) + struct query_info* lookup_qinfo, int* is_expired) { hashvalue_type h; struct lruhash_entry* e; @@ -321,6 +321,7 @@ mesh_serve_expired_lookup(struct module_qstate* qstate, time_t timenow = *qstate->env->now; int must_validate = (!(qstate->query_flags&BIT_CD) || qstate->env->cfg->ignore_cd) && qstate->env->need_to_validate; + *is_expired = 0; /* Lookup cache */ h = query_info_hash(lookup_qinfo, qstate->query_flags); e = slabhash_lookup(qstate->env->msg_cache, h, lookup_qinfo, 0); @@ -328,6 +329,7 @@ mesh_serve_expired_lookup(struct module_qstate* qstate, key = (struct msgreply_entry*)e->key; data = (struct reply_info*)e->data; + if(data->ttl < timenow) *is_expired = 1; msg = tomsg(qstate->env, &key->key, data, qstate->region, timenow, qstate->env->cfg->serve_expired, qstate->env->scratch); if(!msg) @@ -2176,6 +2178,7 @@ mesh_serve_expired_callback(void* arg) int must_validate = (!(qstate->query_flags&BIT_CD) || qstate->env->cfg->ignore_cd) && qstate->env->need_to_validate; int i = 0; + int is_expired; if(!qstate->serve_expired_data) return; verbose(VERB_ALGO, "Serve expired: Trying to reply with expired data"); comm_timer_delete(qstate->serve_expired_data->timer); @@ -2193,7 +2196,7 @@ mesh_serve_expired_callback(void* arg) fptr_ok(fptr_whitelist_serve_expired_lookup( qstate->serve_expired_data->get_cached_answer)); msg = (*qstate->serve_expired_data->get_cached_answer)(qstate, - lookup_qinfo); + lookup_qinfo, &is_expired); if(!msg) return; /* Reset these in case we pass a second time from here. */ @@ -2285,8 +2288,10 @@ mesh_serve_expired_callback(void* arg) /* Add EDE Stale Answer (RCF8914). Ignore global ede as this is * warning instead of an error */ - if (r->edns.edns_present && qstate->env->cfg->ede_serve_expired && - qstate->env->cfg->ede) { + if(r->edns.edns_present && + qstate->env->cfg->ede_serve_expired && + qstate->env->cfg->ede && + is_expired) { edns_opt_list_append_ede(&r->edns.opt_list_out, mstate->s.region, LDNS_EDE_STALE_ANSWER, NULL); } diff --git a/services/mesh.h b/services/mesh.h index 5bd53e065..26ececbe6 100644 --- a/services/mesh.h +++ b/services/mesh.h @@ -673,11 +673,12 @@ void mesh_serve_expired_callback(void* arg); * the same behavior as when replying from cache. * @param qstate: the module qstate. * @param lookup_qinfo: the query info to look for in the cache. + * @param is_expired: set if the cached answer is expired. * @return dns_msg if a cached answer was found, otherwise NULL. */ struct dns_msg* mesh_serve_expired_lookup(struct module_qstate* qstate, - struct query_info* lookup_qinfo); + struct query_info* lookup_qinfo, int* is_expired); /** * See if the mesh has space for more queries. You can allocate queries diff --git a/services/rpz.c b/services/rpz.c index 1ee143f84..3b92ee538 100644 --- a/services/rpz.c +++ b/services/rpz.c @@ -1969,6 +1969,7 @@ rpz_synthesize_nodata(struct rpz* ATTR_UNUSED(r), struct module_qstate* ms, 0, /* ttl */ 0, /* prettl */ 0, /* expttl */ + 0, /* norecttl */ 0, /* an */ 0, /* ns */ 0, /* ar */ @@ -1999,6 +2000,7 @@ rpz_synthesize_nxdomain(struct rpz* r, struct module_qstate* ms, 0, /* ttl */ 0, /* prettl */ 0, /* expttl */ + 0, /* norecttl */ 0, /* an */ 0, /* ns */ 0, /* ar */ @@ -2031,6 +2033,7 @@ rpz_synthesize_localdata_from_rrset(struct rpz* ATTR_UNUSED(r), struct module_qs 0, /* ttl */ 0, /* prettl */ 0, /* expttl */ + 0, /* norecttl */ 1, /* an */ 0, /* ns */ 0, /* ar */ @@ -2176,6 +2179,7 @@ rpz_synthesize_cname_override_msg(struct rpz* r, struct module_qstate* ms, 0, /* ttl */ 0, /* prettl */ 0, /* expttl */ + 0, /* norecttl */ 1, /* an */ 0, /* ns */ 0, /* ar */ diff --git a/testcode/unitmain.c b/testcode/unitmain.c index 084c12b93..9129d722b 100644 --- a/testcode/unitmain.c +++ b/testcode/unitmain.c @@ -1232,7 +1232,7 @@ static void edns_ede_answer_encode_test(void) unit_assert(region); rep = construct_reply_info_base(region, LDNS_RCODE_NOERROR | BIT_QR, 1, - 3600, 3600, 3600, + 3600, 3600, 3600, 0, 0, 0, 0, 0, sec_status_unchecked, LDNS_EDE_NONE); unit_assert(rep); diff --git a/testdata/serve_expired_cached_servfail.rpl b/testdata/serve_expired_cached_servfail.rpl index f5f4c7030..edec74479 100644 --- a/testdata/serve_expired_cached_servfail.rpl +++ b/testdata/serve_expired_cached_servfail.rpl @@ -38,7 +38,7 @@ RANGE_BEGIN 0 20 RANGE_END ; ns.example.com. -RANGE_BEGIN 30 100 +RANGE_BEGIN 40 100 ADDRESS 1.2.3.4 ENTRY_BEGIN MATCH opcode qtype qname diff --git a/testdata/serve_expired_cached_servfail_refresh.rpl b/testdata/serve_expired_cached_servfail_refresh.rpl index 9b7c1fda1..4d14dd948 100644 --- a/testdata/serve_expired_cached_servfail_refresh.rpl +++ b/testdata/serve_expired_cached_servfail_refresh.rpl @@ -15,7 +15,7 @@ stub-zone: stub-addr: 1.2.3.4 CONFIG_END -SCENARIO_BEGIN Test serve-expired with client-timeout and a SERVFAIL upstream reply +SCENARIO_BEGIN Test serve-expired without client-timeout and a SERVFAIL upstream reply ; Scenario overview: ; - query for example.com. IN A ; - answer from upstream is SERVFAIL; will be cached for NORR_TTL(5) diff --git a/testdata/serve_expired_client_timeout_servfail.rpl b/testdata/serve_expired_client_timeout_servfail.rpl index 51aa04370..cea216d4c 100644 --- a/testdata/serve_expired_client_timeout_servfail.rpl +++ b/testdata/serve_expired_client_timeout_servfail.rpl @@ -22,7 +22,13 @@ SCENARIO_BEGIN Test serve-expired with client-timeout and a SERVFAIL upstream re ; - check that we get an answer for example.com. IN A with the correct TTL ; - query again right after the TTL expired ; - answer from upstream is servfail -; - check that we get the expired cached answer instead +; - (expired cached answer will not be replaced, instead marked as unresolvable for NORR_TTL(5)) +; - check that we get the expired cached answer +; - query again (the answer is available on the upstream server now) +; - check that we get the immediate expired answer back instead +; - (the upstream query does happen after the expired reply and updates the cache) +; - query again (the upstream has no answer) +; - check that we get the freshly cached answer ; ns.example.com. RANGE_BEGIN 0 20 @@ -55,7 +61,7 @@ RANGE_BEGIN 0 20 RANGE_END ; ns.example.com. -RANGE_BEGIN 30 70 +RANGE_BEGIN 30 40 ADDRESS 1.2.3.4 ; response to A query ENTRY_BEGIN @@ -67,6 +73,25 @@ RANGE_BEGIN 30 70 ENTRY_END RANGE_END +; ns.example.com. +RANGE_BEGIN 50 60 + ADDRESS 1.2.3.4 + ; response to A query + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + example.com. IN A + SECTION ANSWER + example.com. 10 IN A 5.6.7.8 + SECTION AUTHORITY + example.com. 10 IN NS ns.example.com. + SECTION ADDITIONAL + ns.example.com. 10 IN A 1.2.3.4 + ENTRY_END +RANGE_END + ; Query with RD flag STEP 1 QUERY ENTRY_BEGIN @@ -101,7 +126,7 @@ ENTRY_BEGIN example.com. IN A ENTRY_END -; Check that we got a stale answer +; Check that we got a stale answer because of the upstream SERVFAIL STEP 40 CHECK_ANSWER ENTRY_BEGIN MATCH all ttl ede=3 @@ -116,4 +141,56 @@ ENTRY_BEGIN ns.example.com. 123 IN A 1.2.3.4 ENTRY_END +; Query again +STEP 50 QUERY +ENTRY_BEGIN + REPLY RD DO + SECTION QUESTION + example.com. IN A +ENTRY_END + +; Allow for upstream query to resolve. +STEP 51 TRAFFIC + +; Check that we got an immediate stale answer because of the previous failure, +; regardless if upstream has the answer already in this range. The query will +; be resolved after the immediate cached answer and will cache the result. +STEP 60 CHECK_ANSWER +ENTRY_BEGIN + MATCH all ttl ede=3 + REPLY QR RD RA DO NOERROR + SECTION QUESTION + example.com. IN A + SECTION ANSWER + example.com. 123 IN A 5.6.7.8 + SECTION AUTHORITY + example.com. 123 IN NS ns.example.com. + SECTION ADDITIONAL + ns.example.com. 123 IN A 1.2.3.4 +ENTRY_END + +; Query again +STEP 70 QUERY +ENTRY_BEGIN + REPLY RD + SECTION QUESTION + example.com. IN A +ENTRY_END + +; Check that we got the cached updated answer from the previous step since +; there is no upstream in this range. +STEP 80 CHECK_ANSWER +ENTRY_BEGIN + MATCH all ttl + REPLY QR RD RA NOERROR + SECTION QUESTION + example.com. IN A + SECTION ANSWER + example.com. 10 IN A 5.6.7.8 + SECTION AUTHORITY + example.com. 10 IN NS ns.example.com. + SECTION ADDITIONAL + ns.example.com. 10 IN A 1.2.3.4 +ENTRY_END + SCENARIO_END diff --git a/testdata/serve_expired_client_timeout_val_bogus.rpl b/testdata/serve_expired_client_timeout_val_bogus.rpl new file mode 100644 index 000000000..f4937a16c --- /dev/null +++ b/testdata/serve_expired_client_timeout_val_bogus.rpl @@ -0,0 +1,317 @@ +; config options +; The island of trust is at example.com +server: + trust-anchor: "example.com. 3600 IN DS 2854 3 1 46e4ffc6e9a4793b488954bd3f0cc6af0dfb201b" + val-override-date: "20070916134226" + target-fetch-policy: "0 0 0 0 0" + qname-minimisation: "no" + fake-sha1: yes + trust-anchor-signaling: no + minimal-responses: no + + serve-expired: yes + serve-expired-client-timeout: 1 + serve-expired-reply-ttl: 123 + ede: yes + ede-serve-expired: yes + + # No need for AAAA nameserver queries + do-ip6: no + +stub-zone: + name: "." + stub-addr: 193.0.14.129 # K.ROOT-SERVERS.NET. +CONFIG_END + +SCENARIO_BEGIN Test serve-expired with client-timeout and bogus answer +; Scenario overview: +; - query for www.example.com. IN A +; - check the answer +; - wait for the record to expire +; - (upstream now has a bogus response) +; - query again for www.example.com. IN A +; - check that we get the expired valid response instead +; - query once more +; - (upstream has the valid response again) +; - check that we get the immediate expired valid response +; - (the prefetch query updates the cache with the valid response) +; - query one last time +; - check that we get the immediate valid cache response; upstream does not have an answer at this moment + +;; +;; K.ROOT-SERVERS.NET. +;; +RANGE_BEGIN 0 100 + ADDRESS 193.0.14.129 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + . IN NS + SECTION ANSWER + . IN NS K.ROOT-SERVERS.NET. + SECTION ADDITIONAL + K.ROOT-SERVERS.NET. IN A 193.0.14.129 + ENTRY_END + + ENTRY_BEGIN + MATCH opcode + ADJUST copy_id copy_query + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION AUTHORITY + com. IN NS a.gtld-servers.net. + SECTION ADDITIONAL + a.gtld-servers.net. IN A 192.5.6.30 + ENTRY_END +RANGE_END + +;; +;; a.gtld-servers.net. +;; +RANGE_BEGIN 0 100 + ADDRESS 192.5.6.30 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + com. IN NS + SECTION ANSWER + com. IN NS a.gtld-servers.net. + SECTION ADDITIONAL + a.gtld-servers.net. IN A 192.5.6.30 + ENTRY_END + + ENTRY_BEGIN + MATCH opcode + ADJUST copy_id copy_query + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION AUTHORITY + example.com. IN NS ns.example.com. + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with generic valid data +;; +RANGE_BEGIN 0 100 + ADDRESS 1.2.3.4 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + example.com. IN NS + SECTION ANSWER + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926135752 20070829135752 2854 example.com. MC0CFQCMSWxVehgOQLoYclB9PIAbNP229AIUeH0vNNGJhjnZiqgIOKvs1EhzqAo= ;{id = 2854} + ENTRY_END + + ; response to DNSKEY priming query + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + example.com. IN DNSKEY + SECTION ANSWER + example.com. 3600 IN DNSKEY 256 3 3 ALXLUsWqUrY3JYER3T4TBJII s70j+sDS/UT2QRp61SE7S3E EXopNXoFE73JLRmvpi/UrOO/Vz4Se 6wXv/CYCKjGw06U4WRgR YXcpEhJROyNapmdIKSx hOzfLVE1gqA0PweZR8d tY3aNQSRn3sPpwJr6Mi /PqQKAMMrZ9ckJpf1+b QMOOvxgzz2U1GS18b3y ZKcgTMEaJzd/GZYzi/B N2DzQ0MsrSwYXfsNLFO Bbs8PJMW4LYIxeeOe6rUgkWOF 7CC9Dh/dduQ1QrsJhmZAEFfd6ByYV+ ;{id = 2854 (zsk), size = 1688b} + example.com. 3600 IN RRSIG DNSKEY 3 2 3600 20070926134802 20070829134802 2854 example.com. MCwCFG1yhRNtTEa3Eno2zhVVuy2EJX3wAhQeLyUp6+UXcpC5qGNu9tkrTEgPUg== ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926135752 20070829135752 2854 example.com. MC0CFQCMSWxVehgOQLoYclB9PIAbNP229AIUeH0vNNGJhjnZiqgIOKvs1EhzqAo= ;{id = 2854} + ENTRY_END +RANGE_END + +;; +;; ns.example.com with valid data +;; +RANGE_BEGIN 0 10 + ADDRESS 1.2.3.4 + ; response to query of interest + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with bogus data +;; +RANGE_BEGIN 20 30 + ADDRESS 1.2.3.4 + ; response to query of interest (bogus answer) + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ;; (valid signature) + ;; www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ;; (bogus signature) + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with valid data again +;; +RANGE_BEGIN 40 60 + ADDRESS 1.2.3.4 + ; response to query of interest + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ENTRY_END +RANGE_END + +STEP 1 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; recursion happens here. +STEP 10 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. IN A 10.20.30.40 +www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. IN NS ns.example.com. +example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. IN A 1.2.3.4 +ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +STEP 11 TIME_PASSES ELAPSE 3601 + +STEP 20 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; expired answer because upstream is bogus +STEP 30 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 123 IN A 10.20.30.40 +www.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. 123 IN NS ns.example.com. +example.com. 123 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. 123 IN A 1.2.3.4 +ns.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +STEP 40 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; immediate cached answer because upstream is valid again +STEP 50 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 123 IN A 10.20.30.40 +www.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. 123 IN NS ns.example.com. +example.com. 123 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. 123 IN A 1.2.3.4 +ns.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +; upstream query is resolved before this query comes in +STEP 60 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; prefetch query updated the cache, since there is no upstream response in this range +STEP 70 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. IN A 10.20.30.40 +www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. IN NS ns.example.com. +example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. IN A 1.2.3.4 +ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +SCENARIO_END diff --git a/testdata/serve_expired_client_timeout_val_insecure_delegation.rpl b/testdata/serve_expired_client_timeout_val_insecure_delegation.rpl new file mode 100644 index 000000000..6654a2c68 --- /dev/null +++ b/testdata/serve_expired_client_timeout_val_insecure_delegation.rpl @@ -0,0 +1,247 @@ +; config options +server: + trust-anchor: "example. DNSKEY 257 3 7 AwEAAcUlFV1vhmqx6NSOUOq2R/dsR7Xm3upJ ( j7IommWSpJABVfW8Q0rOvXdM6kzt+TAu92L9 AbsUdblMFin8CVF3n4s= )" + val-override-date: "20120420235959" + val-max-restart: 0 + outbound-msg-retry: 0 + target-fetch-policy: "0 0 0 0 0" + qname-minimisation: "no" + fake-sha1: yes + trust-anchor-signaling: no + minimal-responses: no + rrset-roundrobin: no + + serve-expired: yes + serve-expired-client-timeout: 1 + serve-expired-reply-ttl: 123 + ede: yes + ede-serve-expired: yes + + # No need for AAAA nameserver queries + do-ip6: no + +stub-zone: + name: "." + stub-addr: 193.0.14.129 # K.ROOT-SERVERS.NET. +CONFIG_END + +SCENARIO_BEGIN Test serve-expired with client-timeout and failed DNSSEC parent of insecure zone +; Scenario overview: +; - query for mc.c.example. IN MX +; - check the answer +; - wait for all the records to expire +; - (example. now has a bogus DNSKEY response) +; - query again for mc.c.example. IN MX +; - (validator fails priming the trust anchor because of the bogus DNSKEY) +; - check that we get the expired insecure response instead + +;; +;; K.ROOT-SERVERS.NET. +;; +RANGE_BEGIN 0 100 + ADDRESS 193.0.14.129 +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR NOERROR +SECTION QUESTION +. IN NS +SECTION ANSWER +. IN NS K.ROOT-SERVERS.NET. +SECTION ADDITIONAL +K.ROOT-SERVERS.NET. IN A 193.0.14.129 +ENTRY_END + +ENTRY_BEGIN +MATCH opcode +ADJUST copy_id copy_query +REPLY QR NOERROR +SECTION QUESTION +. IN A +SECTION AUTHORITY +example. IN NS ns1.example. +SECTION ADDITIONAL +ns1.example. IN A 192.0.2.1 +ENTRY_END +RANGE_END + +;; +;; ns1.example. generic data +;; +RANGE_BEGIN 0 100 + ADDRESS 192.0.2.1 +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id copy_query +REPLY QR REFUSED +SECTION QUESTION +example. IN NS +SECTION ANSWER +ENTRY_END + +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR AA NOERROR +SECTION QUESTION +ns1.example. IN A +SECTION ANSWER +ns1.example. IN A 192.0.2.1 +ENTRY_END + +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR AA DO NOERROR +SECTION QUESTION +mc.c.example. IN MX +SECTION AUTHORITY +;; NSEC3 RR that covers the "next closer" name (c.example) +;; H(c.example) = 4g6p9u5gvfshp30pqecj98b3maqbn1ck +35mthgpgcu1qg68fab165klnsnk3dpvl.example. NSEC3 1 1 12 aabbccdd ( b4um86eghhds6nea196smvmlo4ors995 NS DS RRSIG ) +35mthgpgcu1qg68fab165klnsnk3dpvl.example. RRSIG NSEC3 7 2 3600 20150420235959 20051021000000 ( 40430 example. g6jPUUpduAJKRljUsN8gB4UagAX0NxY9shwQ Aynzo8EUWH+z6hEIBlUTPGj15eZll6VhQqgZ XtAIR3chwgW+SA== ) +;; NSEC3 RR that matches the closest encloser (example) +;; H(example) = 0p9mhaveqvm6t7vbl5lop2u3t2rp3tom +0p9mhaveqvm6t7vbl5lop2u3t2rp3tom.example. NSEC3 1 1 12 aabbccdd ( 2t7b4g4vsa5smi47k61mv5bv1a22bojr MX DNSKEY NS SOA NSEC3PARAM RRSIG ) +0p9mhaveqvm6t7vbl5lop2u3t2rp3tom.example. RRSIG NSEC3 7 2 3600 20150420235959 20051021000000 ( 40430 example. OSgWSm26B+cS+dDL8b5QrWr/dEWhtCsKlwKL IBHYH6blRxK9rC0bMJPwQ4mLIuw85H2EY762 BOCXJZMnpuwhpA== ) +c.example. NS ns1.c.example. +SECTION ADDITIONAL +ns1.c.example. A 192.0.2.7 +ENTRY_END + +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR AA DO NOERROR +SECTION QUESTION +c.example. IN DS +SECTION AUTHORITY +;; NSEC3 RR that covers the "next closer" name (c.example) +;; H(c.example) = 4g6p9u5gvfshp30pqecj98b3maqbn1ck +35mthgpgcu1qg68fab165klnsnk3dpvl.example. NSEC3 1 1 12 aabbccdd ( b4um86eghhds6nea196smvmlo4ors995 NS DS RRSIG ) +35mthgpgcu1qg68fab165klnsnk3dpvl.example. RRSIG NSEC3 7 2 3600 20150420235959 20051021000000 ( 40430 example. g6jPUUpduAJKRljUsN8gB4UagAX0NxY9shwQ Aynzo8EUWH+z6hEIBlUTPGj15eZll6VhQqgZ XtAIR3chwgW+SA== ) +;; NSEC3 RR that matches the closest encloser (example) +;; H(example) = 0p9mhaveqvm6t7vbl5lop2u3t2rp3tom +0p9mhaveqvm6t7vbl5lop2u3t2rp3tom.example. NSEC3 1 1 12 aabbccdd ( 2t7b4g4vsa5smi47k61mv5bv1a22bojr MX DNSKEY NS SOA NSEC3PARAM RRSIG ) +0p9mhaveqvm6t7vbl5lop2u3t2rp3tom.example. RRSIG NSEC3 7 2 3600 20150420235959 20051021000000 ( 40430 example. OSgWSm26B+cS+dDL8b5QrWr/dEWhtCsKlwKL IBHYH6blRxK9rC0bMJPwQ4mLIuw85H2EY762 BOCXJZMnpuwhpA== ) +ENTRY_END +RANGE_END + +;; +;; ns1.example. with valid DNSKEY data +;; +RANGE_BEGIN 0 20 + ADDRESS 192.0.2.1 +; response to DNSKEY priming query +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR NOERROR +SECTION QUESTION +example. IN DNSKEY +SECTION ANSWER +example. DNSKEY 256 3 7 AwEAAaetidLzsKWUt4swWR8yu0wPHPiUi8LU ( sAD0QPWU+wzt89epO6tHzkMBVDkC7qphQO2h TY4hHn9npWFRw5BYubE= ) +example. DNSKEY 257 3 7 AwEAAcUlFV1vhmqx6NSOUOq2R/dsR7Xm3upJ ( j7IommWSpJABVfW8Q0rOvXdM6kzt+TAu92L9 AbsUdblMFin8CVF3n4s= ) +example. RRSIG DNSKEY 7 1 3600 20150420235959 ( 20051021000000 12708 example. AuU4juU9RaxescSmStrQks3Gh9FblGBlVU31 uzMZ/U/FpsUb8aC6QZS+sTsJXnLnz7flGOsm MGQZf3bH+QsCtg== ) +ENTRY_END +RANGE_END + +;; +;; ns1.example. with bogus DNSKEY data +;; +RANGE_BEGIN 30 40 + ADDRESS 192.0.2.1 +; response to DNSKEY priming query +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR NOERROR +SECTION QUESTION +example. IN DNSKEY +SECTION ANSWER +example. DNSKEY 256 3 7 AwEAAaetidLzsKWUt4swWR8yu0wPHPiUi8LU ( sAD0QPWU+wzt89epO6tHzkMBVDkC7qphQO2h TY4hHn9npWFRw5BYubE= ) +example. DNSKEY 257 3 7 AwEAAcUlFV1vhmqx6NSOUOq2R/dsR7Xm3upJ ( j7IommWSpJABVfW8Q0rOvXdM6kzt+TAu92L9 AbsUdblMFin8CVF3n4s= ) +;; (bogus signature) +example. RRSIG DNSKEY 7 1 3600 20150420235959 20051021000000 12708 example. +ENTRY_END +RANGE_END + +;; +;; ns1.c.example. +;; +RANGE_BEGIN 0 100 + ADDRESS 192.0.2.7 +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR AA NOERROR +SECTION QUESTION +c.example. IN NS +SECTION ANSWER +c.example. NS ns1.c.example. +SECTION ADDITIONAL +ns1.c.example. A 192.0.2.7 +ENTRY_END + +ENTRY_BEGIN +MATCH opcode qtype qname +ADJUST copy_id +REPLY QR AA NOERROR +SECTION QUESTION +mc.c.example. IN MX +SECTION ANSWER +mc.c.example. IN MX 50 mx.c.example. +SECTION AUTHORITY +c.example. NS ns1.c.example. +SECTION ADDITIONAL +ns1.c.example. A 192.0.2.7 +ENTRY_END +RANGE_END + + +STEP 0 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +mc.c.example. IN MX +ENTRY_END + +; recursion happens here. +STEP 10 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RD RA DO NOERROR +SECTION QUESTION +mc.c.example. IN MX +SECTION ANSWER +mc.c.example. IN MX 50 mx.c.example. +SECTION AUTHORITY +c.example. NS ns1.c.example. +SECTION ADDITIONAL +ns1.c.example. A 192.0.2.7 +ENTRY_END + +STEP 20 TIME_PASSES ELAPSE 3601 + +STEP 30 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +mc.c.example. IN MX +ENTRY_END + +STEP 40 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RD RA DO NOERROR +SECTION QUESTION +mc.c.example. IN MX +SECTION ANSWER +mc.c.example. 123 IN MX 50 mx.c.example. +SECTION AUTHORITY +c.example. 123 NS ns1.c.example. +SECTION ADDITIONAL +ns1.c.example. 123 A 192.0.2.7 +ENTRY_END + +SCENARIO_END diff --git a/testdata/serve_expired_ttl_reset.rpl b/testdata/serve_expired_ttl_reset.rpl new file mode 100644 index 000000000..521d5a0f0 --- /dev/null +++ b/testdata/serve_expired_ttl_reset.rpl @@ -0,0 +1,102 @@ +; config options go here. +server: + serve-expired: yes + serve-expired-ttl: 1 + serve-expired-ttl-reset: yes + serve-expired-reply-ttl: 123 + ede: yes + ede-serve-expired: yes +forward-zone: name: "." forward-addr: 216.0.0.1 +CONFIG_END +SCENARIO_BEGIN Serve expired ttl with reset on forwarder with a timeout on upstream query +; Scenario overview: +; - Send query +; - Get reply +; - Wait for it to expire (+ serve-expired-ttl) +; - Send query again +; - Upstream timeouts +; - Error response from iterator SERVFAIL, resets expired-ttl on cache +; - Check we are getting the SERVFAIL response +; - Query again +; - Check we are getting the expired answer +; - Upstream still timeouts + +STEP 1 QUERY +ENTRY_BEGIN +REPLY RD +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; Upstream reply +STEP 2 REPLY +ENTRY_BEGIN +REPLY QR AA NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 10 IN A 0.0.0.0 +ENTRY_END + +STEP 3 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RA RD NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 10 IN A 0.0.0.0 +ENTRY_END + +; Expire the record (+ serve-expired-ttl) +STEP 4 TIME_PASSES ELAPSE 12 + +STEP 5 QUERY +ENTRY_BEGIN +REPLY RD +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; But the pending query times out! +; outbound-msg-retry times timeout. +STEP 6 TIMEOUT +STEP 7 TIMEOUT +STEP 8 TIMEOUT +STEP 9 TIMEOUT +STEP 10 TIMEOUT + +; Returns servfail +; but error response from iterator resets the expired ttl +STEP 11 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RA RD SERVFAIL +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; Query again +STEP 12 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; Check that we get the expired answer +STEP 13 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RA RD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 123 IN A 0.0.0.0 +ENTRY_END + +; But the pending query times out! +; Only one because RTT reached the limit. +STEP 16 TIMEOUT + +SCENARIO_END diff --git a/testdata/serve_expired_val_bogus.rpl b/testdata/serve_expired_val_bogus.rpl new file mode 100644 index 000000000..35365beef --- /dev/null +++ b/testdata/serve_expired_val_bogus.rpl @@ -0,0 +1,316 @@ +; config options +; The island of trust is at example.com +server: + trust-anchor: "example.com. 3600 IN DS 2854 3 1 46e4ffc6e9a4793b488954bd3f0cc6af0dfb201b" + val-override-date: "20070916134226" + target-fetch-policy: "0 0 0 0 0" + qname-minimisation: "no" + fake-sha1: yes + trust-anchor-signaling: no + minimal-responses: no + + serve-expired: yes + serve-expired-reply-ttl: 123 + ede: yes + ede-serve-expired: yes + + # No need for AAAA nameserver queries + do-ip6: no + +stub-zone: + name: "." + stub-addr: 193.0.14.129 # K.ROOT-SERVERS.NET. +CONFIG_END + +SCENARIO_BEGIN Test serve-expired with client-timeout and bogus answer +; Scenario overview: +; - query for www.example.com. IN A +; - check the answer +; - wait for the record to expire +; - (upstream now has a bogus response) +; - query again for www.example.com. IN A +; - check that we get the immediate expired valid response +; - (prefetch response is bogus and is not cached) +; - query once more +; - check that we still get the immediate expired valid response and not the fresh bogus one +; - (upstream has a valid response again; prefetch will update the cache) +; - query one last time +; - check that we get an immediate valid cache response + +;; +;; K.ROOT-SERVERS.NET. +;; +RANGE_BEGIN 0 100 + ADDRESS 193.0.14.129 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + . IN NS + SECTION ANSWER + . IN NS K.ROOT-SERVERS.NET. + SECTION ADDITIONAL + K.ROOT-SERVERS.NET. IN A 193.0.14.129 + ENTRY_END + + ENTRY_BEGIN + MATCH opcode + ADJUST copy_id copy_query + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION AUTHORITY + com. IN NS a.gtld-servers.net. + SECTION ADDITIONAL + a.gtld-servers.net. IN A 192.5.6.30 + ENTRY_END +RANGE_END + +;; +;; a.gtld-servers.net. +;; +RANGE_BEGIN 0 100 + ADDRESS 192.5.6.30 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + com. IN NS + SECTION ANSWER + com. IN NS a.gtld-servers.net. + SECTION ADDITIONAL + a.gtld-servers.net. IN A 192.5.6.30 + ENTRY_END + + ENTRY_BEGIN + MATCH opcode + ADJUST copy_id copy_query + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION AUTHORITY + example.com. IN NS ns.example.com. + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with generic data +;; +RANGE_BEGIN 0 100 + ADDRESS 1.2.3.4 + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + example.com. IN NS + SECTION ANSWER + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926135752 20070829135752 2854 example.com. MC0CFQCMSWxVehgOQLoYclB9PIAbNP229AIUeH0vNNGJhjnZiqgIOKvs1EhzqAo= ;{id = 2854} + ENTRY_END + + ; response to DNSKEY priming query + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + example.com. IN DNSKEY + SECTION ANSWER + example.com. 3600 IN DNSKEY 256 3 3 ALXLUsWqUrY3JYER3T4TBJII s70j+sDS/UT2QRp61SE7S3E EXopNXoFE73JLRmvpi/UrOO/Vz4Se 6wXv/CYCKjGw06U4WRgR YXcpEhJROyNapmdIKSx hOzfLVE1gqA0PweZR8d tY3aNQSRn3sPpwJr6Mi /PqQKAMMrZ9ckJpf1+b QMOOvxgzz2U1GS18b3y ZKcgTMEaJzd/GZYzi/B N2DzQ0MsrSwYXfsNLFO Bbs8PJMW4LYIxeeOe6rUgkWOF 7CC9Dh/dduQ1QrsJhmZAEFfd6ByYV+ ;{id = 2854 (zsk), size = 1688b} + example.com. 3600 IN RRSIG DNSKEY 3 2 3600 20070926134802 20070829134802 2854 example.com. MCwCFG1yhRNtTEa3Eno2zhVVuy2EJX3wAhQeLyUp6+UXcpC5qGNu9tkrTEgPUg== ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926135752 20070829135752 2854 example.com. MC0CFQCMSWxVehgOQLoYclB9PIAbNP229AIUeH0vNNGJhjnZiqgIOKvs1EhzqAo= ;{id = 2854} + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with valid data +;; +RANGE_BEGIN 0 10 + ADDRESS 1.2.3.4 + ; response to query of interest + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with bogus data +;; +RANGE_BEGIN 20 40 + ADDRESS 1.2.3.4 + ; response to query of interest (bogus answer) + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + ;; (valid signature) + ;; www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ;; (bogus signature) + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. + ENTRY_END +RANGE_END + +;; +;; ns.example.com. with valid data again +;; +RANGE_BEGIN 50 100 + ADDRESS 1.2.3.4 + ; response to query of interest + ENTRY_BEGIN + MATCH opcode qtype qname + ADJUST copy_id + REPLY QR NOERROR + SECTION QUESTION + www.example.com. IN A + SECTION ANSWER + www.example.com. IN A 10.20.30.40 + ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} + SECTION AUTHORITY + example.com. IN NS ns.example.com. + example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} + SECTION ADDITIONAL + ns.example.com. IN A 1.2.3.4 + www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} + ENTRY_END +RANGE_END + + +STEP 1 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; this is the valid answer +STEP 10 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. IN A 10.20.30.40 +www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. IN NS ns.example.com. +example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. IN A 1.2.3.4 +ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +STEP 11 TIME_PASSES ELAPSE 3601 + +STEP 20 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; this is the immediate expired cache response +STEP 30 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 123 IN A 10.20.30.40 +www.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. 123 IN NS ns.example.com. +example.com. 123 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. 123 IN A 1.2.3.4 +ns.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +STEP 40 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; this is still the immediate cache response because the previous upstream response was bogus +STEP 50 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl ede=3 +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. 123 IN A 10.20.30.40 +www.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. 123 IN NS ns.example.com. +example.com. 123 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. 123 IN A 1.2.3.4 +ns.example.com. 123 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +STEP 60 QUERY +ENTRY_BEGIN +REPLY RD DO +SECTION QUESTION +www.example.com. IN A +ENTRY_END + +; this is the immediate cache response because the previous upstream response was valid +STEP 70 CHECK_ANSWER +ENTRY_BEGIN +MATCH all ttl +REPLY QR RD RA AD DO NOERROR +SECTION QUESTION +www.example.com. IN A +SECTION ANSWER +www.example.com. IN A 10.20.30.40 +www.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFC99iE9K5y2WNgI0gFvBWaTi9wm6AhUAoUqOpDtG5Zct+Qr9F3mSdnbc6V4= ;{id = 2854} +SECTION AUTHORITY +example.com. IN NS ns.example.com. +example.com. 3600 IN RRSIG NS 3 2 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCN+qHdJxoI/2tNKwsb08pra/G7aAIUAWA5sDdJTbrXA1/3OaesGBAO3sI= ;{id = 2854} +SECTION ADDITIONAL +ns.example.com. IN A 1.2.3.4 +ns.example.com. 3600 IN RRSIG A 3 3 3600 20070926134150 20070829134150 2854 example.com. MC0CFQCQMyTjn7WWwpwAR1LlVeLpRgZGuQIUCcJDEkwAuzytTDRlYK7nIMwH1CM= ;{id = 2854} +ENTRY_END + +SCENARIO_END diff --git a/util/config_file.c b/util/config_file.c index ab63d3fed..3898a8b0a 100644 --- a/util/config_file.c +++ b/util/config_file.c @@ -719,7 +719,9 @@ int config_set_option(struct config_file* cfg, const char* opt, SERVE_EXPIRED = cfg->serve_expired; } else if(strcmp(opt, "serve-expired-ttl:") == 0) { IS_NUMBER_OR_ZERO; cfg->serve_expired_ttl = atoi(val); SERVE_EXPIRED_TTL=(time_t)cfg->serve_expired_ttl;} - else S_YNO("serve-expired-ttl-reset:", serve_expired_ttl_reset) + else if(strcmp(opt, "serve-expired-ttl-reset:") == 0) + { IS_YES_OR_NO; cfg->serve_expired_ttl_reset = (strcmp(val, "yes") == 0); + SERVE_EXPIRED_TTL_RESET = cfg->serve_expired_ttl_reset; } else if(strcmp(opt, "serve-expired-reply-ttl:") == 0) { IS_NUMBER_OR_ZERO; cfg->serve_expired_reply_ttl = atoi(val); SERVE_EXPIRED_REPLY_TTL=(time_t)cfg->serve_expired_reply_ttl;} else S_NUMBER_OR_ZERO("serve-expired-client-timeout:", serve_expired_client_timeout) @@ -2395,6 +2397,7 @@ config_apply(struct config_file* config) MIN_TTL = (time_t)config->min_ttl; SERVE_EXPIRED = config->serve_expired; SERVE_EXPIRED_TTL = (time_t)config->serve_expired_ttl; + SERVE_EXPIRED_TTL_RESET = config->serve_expired_ttl_reset; SERVE_EXPIRED_REPLY_TTL = (time_t)config->serve_expired_reply_ttl; SERVE_ORIGINAL_TTL = config->serve_original_ttl; MAX_NEG_TTL = (time_t)config->max_negative_ttl; diff --git a/util/data/msgparse.h b/util/data/msgparse.h index aebd48efa..62f0d5aac 100644 --- a/util/data/msgparse.h +++ b/util/data/msgparse.h @@ -89,6 +89,8 @@ extern time_t MIN_NEG_TTL; extern int SERVE_EXPIRED; /** Time to serve records after expiration */ extern time_t SERVE_EXPIRED_TTL; +/** Reset serve expired TTL after failed update attempt */ +extern time_t SERVE_EXPIRED_TTL_RESET; /** TTL to use for expired records */ extern time_t SERVE_EXPIRED_REPLY_TTL; /** Negative cache time (for entries without any RRs.) */ diff --git a/util/data/msgreply.c b/util/data/msgreply.c index c9d7bbf3a..78e4fb1c3 100644 --- a/util/data/msgreply.c +++ b/util/data/msgreply.c @@ -67,6 +67,8 @@ time_t MIN_NEG_TTL = 0; int SERVE_EXPIRED = 0; /** Time to serve records after expiration */ time_t SERVE_EXPIRED_TTL = 0; +/** Reset serve expired TTL after failed update attempt */ +time_t SERVE_EXPIRED_TTL_RESET = 0; /** TTL to use for expired records */ time_t SERVE_EXPIRED_REPLY_TTL = 30; /** If we serve the original TTL or decrementing TTLs */ @@ -95,8 +97,9 @@ parse_create_qinfo(sldns_buffer* pkt, struct msg_parse* msg, /** constructor for replyinfo */ struct reply_info* construct_reply_info_base(struct regional* region, uint16_t flags, size_t qd, - time_t ttl, time_t prettl, time_t expttl, size_t an, size_t ns, - size_t ar, size_t total, enum sec_status sec, sldns_ede_code reason_bogus) + time_t ttl, time_t prettl, time_t expttl, time_t norecttl, size_t an, + size_t ns, size_t ar, size_t total, enum sec_status sec, + sldns_ede_code reason_bogus) { struct reply_info* rep; /* rrset_count-1 because the first ref is part of the struct. */ @@ -114,6 +117,7 @@ construct_reply_info_base(struct regional* region, uint16_t flags, size_t qd, rep->ttl = ttl; rep->prefetch_ttl = prettl; rep->serve_expired_ttl = expttl; + rep->serve_expired_norec_ttl = norecttl; rep->an_numrrsets = an; rep->ns_numrrsets = ns; rep->ar_numrrsets = ar; @@ -139,8 +143,8 @@ static int parse_create_repinfo(struct msg_parse* msg, struct reply_info** rep, struct regional* region) { - *rep = construct_reply_info_base(region, msg->flags, msg->qdcount, 0, - 0, 0, msg->an_rrsets, msg->ns_rrsets, msg->ar_rrsets, + *rep = construct_reply_info_base(region, msg->flags, msg->qdcount, 0, + 0, 0, 0, msg->an_rrsets, msg->ns_rrsets, msg->ar_rrsets, msg->rrset_count, sec_status_unchecked, LDNS_EDE_NONE); if(!*rep) return 0; @@ -171,6 +175,32 @@ reply_info_alloc_rrset_keys(struct reply_info* rep, struct alloc_cache* alloc, return 1; } +int +reply_info_can_answer_expired(struct reply_info* rep, time_t timenow) +{ + log_assert(rep->ttl < timenow); + /* Really expired */ + if(SERVE_EXPIRED_TTL && rep->serve_expired_ttl < timenow) return 0; + /* Ignore expired failure answers */ + if(FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_NOERROR && + FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_NXDOMAIN && + FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_YXDOMAIN) return 0; + return 1; +} + +int reply_info_could_use_expired(struct reply_info* rep, time_t timenow) +{ + log_assert(rep->ttl < timenow); + /* Really expired */ + if(SERVE_EXPIRED_TTL && rep->serve_expired_ttl < timenow && + !SERVE_EXPIRED_TTL_RESET) return 0; + /* Ignore expired failure answers */ + if(FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_NOERROR && + FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_NXDOMAIN && + FLAGS_GET_RCODE(rep->flags) != LDNS_RCODE_YXDOMAIN) return 0; + return 1; +} + struct reply_info * make_new_reply_info(const struct reply_info* rep, struct regional* region, size_t an_numrrsets, size_t copy_rrsets) @@ -185,7 +215,8 @@ make_new_reply_info(const struct reply_info* rep, struct regional* region, * so the total number of RRsets is an_numrrsets. */ new_rep = construct_reply_info_base(region, rep->flags, rep->qdcount, rep->ttl, rep->prefetch_ttl, - rep->serve_expired_ttl, an_numrrsets, 0, 0, an_numrrsets, + rep->serve_expired_ttl, rep->serve_expired_norec_ttl, + an_numrrsets, 0, 0, an_numrrsets, sec_status_insecure, LDNS_EDE_NONE); if(!new_rep) return NULL; @@ -486,6 +517,8 @@ parse_copy_decompress(sldns_buffer* pkt, struct msg_parse* msg, } rep->prefetch_ttl = PREFETCH_TTL_CALC(rep->ttl); rep->serve_expired_ttl = rep->ttl + SERVE_EXPIRED_TTL; + /* rep->serve_expired_norec_ttl should stay at 0 */ + log_assert(rep->serve_expired_norec_ttl == 0); return 1; } @@ -568,6 +601,9 @@ reply_info_set_ttls(struct reply_info* rep, time_t timenow) rep->ttl += timenow; rep->prefetch_ttl += timenow; rep->serve_expired_ttl += timenow; + /* Don't set rep->serve_expired_norec_ttl; this should only be set + * on cached records when encountering an error */ + log_assert(rep->serve_expired_norec_ttl == 0); for(i=0; irrset_count; i++) { struct packed_rrset_data* data = (struct packed_rrset_data*) rep->ref[i].key->entry.data; @@ -763,6 +799,7 @@ reply_info_copy(struct reply_info* rep, struct alloc_cache* alloc, struct reply_info* cp; cp = construct_reply_info_base(region, rep->flags, rep->qdcount, rep->ttl, rep->prefetch_ttl, rep->serve_expired_ttl, + rep->serve_expired_norec_ttl, rep->an_numrrsets, rep->ns_numrrsets, rep->ar_numrrsets, rep->rrset_count, rep->security, rep->reason_bogus); if(!cp) diff --git a/util/data/msgreply.h b/util/data/msgreply.h index 4b93b12c8..d1c2bfa4b 100644 --- a/util/data/msgreply.h +++ b/util/data/msgreply.h @@ -145,7 +145,7 @@ struct reply_info { /** 32 bit padding to pad struct member alignment to 64 bits. */ uint32_t padding; - /** + /** * TTL of the entire reply (for negative caching). * only for use when there are 0 RRsets in this message. * if there are RRsets, check those instead. @@ -158,12 +158,24 @@ struct reply_info { */ time_t prefetch_ttl; - /** + /** * Reply TTL extended with serve expired TTL, to limit time to serve * expired message. */ time_t serve_expired_ttl; + /** + * TTL for an expired entry to be used without attempting recursion + * since a previous recursion attempt failed to update the message. + * This is just an efficiency timer when serve-expired-client-timeout + * is configured. It will make Unbound immediately reply with the + * expired entry instead of trying resolution first. + * It is set on cached entries by modules that identified problems + * while resolving, e.g., failed upstreams from Iterator, or failed + * validation from Validator. + */ + time_t serve_expired_norec_ttl; + /** * The security status from DNSSEC validation of this message. */ @@ -244,6 +256,7 @@ struct msgreply_entry { * @param ttl: TTL of replyinfo * @param prettl: prefetch ttl * @param expttl: serve expired ttl + * @param norecttl: serve expired no recursion ttl * @param an: an count * @param ns: ns count * @param ar: ar count @@ -255,8 +268,8 @@ struct msgreply_entry { */ struct reply_info* construct_reply_info_base(struct regional* region, uint16_t flags, size_t qd, - time_t ttl, time_t prettl, time_t expttl, size_t an, size_t ns, - size_t ar, size_t total, enum sec_status sec, + time_t ttl, time_t prettl, time_t expttl, time_t norecttl, size_t an, + size_t ns, size_t ar, size_t total, enum sec_status sec, sldns_ede_code reason_bogus); /** @@ -399,6 +412,24 @@ struct reply_info* reply_info_copy(struct reply_info* rep, int reply_info_alloc_rrset_keys(struct reply_info* rep, struct alloc_cache* alloc, struct regional* region); +/** + * Check if an *expired* (checked by the caller already) reply info can be used + * as an expired answer. + * @param rep: expired reply info to check. + * @param timenow: the current time. + * @return 1 if it can be used as an answer, 0 otherwise. + */ +int reply_info_can_answer_expired(struct reply_info* rep, time_t timenow); + +/** + * Check if an *expired* (checked by the caller already) reply info could be + * useful data to stay in the cache. + * @param rep: expired reply info to check. + * @param timenow: the current time. + * @return 1 if it is useful, 0 otherwise. + */ +int reply_info_could_use_expired(struct reply_info* rep, time_t timenow); + /* * Create a new reply_info based on 'rep'. The new info is based on * the passed 'rep', but ignores any rrsets except for the first 'an_numrrsets' diff --git a/util/module.h b/util/module.h index 03f3eab0b..abad3c8dd 100644 --- a/util/module.h +++ b/util/module.h @@ -319,13 +319,15 @@ typedef int inplace_cb_query_response_func_type(struct module_qstate* qstate, /** * Function called when looking for (expired) cached answers during the serve * expired logic. - * Called as func(qstate, lookup_qinfo) + * Called as func(qstate, lookup_qinfo, &is_expired) * Where: * qstate: the query state. * lookup_qinfo: the qinfo to lookup for. + * is_expired: set if the cached answer is expired. */ typedef struct dns_msg* serve_expired_lookup_func_type( - struct module_qstate* qstate, struct query_info* lookup_qinfo); + struct module_qstate* qstate, struct query_info* lookup_qinfo, + int* is_expired); /** * Module environment. diff --git a/validator/validator.c b/validator/validator.c index da9215883..857510b65 100644 --- a/validator/validator.c +++ b/validator/validator.c @@ -2435,6 +2435,8 @@ processFinished(struct module_qstate* qstate, struct val_qstate* vq, /* if the result is bogus - set message ttl to bogus ttl to avoid * endless bogus revalidation */ if(vq->orig_msg->rep->security == sec_status_bogus) { + struct msgreply_entry* e; + /* see if we can try again to fetch data */ if(vq->restart_count < ve->max_restart) { verbose(VERB_ALGO, "validation failed, " @@ -2449,10 +2451,51 @@ processFinished(struct module_qstate* qstate, struct val_qstate* vq, return 0; } + if(qstate->env->cfg->serve_expired && + (e=msg_cache_lookup(qstate->env, qstate->qinfo.qname, + qstate->qinfo.qname_len, qstate->qinfo.qtype, + qstate->qinfo.qclass, qstate->query_flags, + 0 /*now; allow expired*/, + 1 /*wr; we may update the data*/))) { + struct reply_info* rep = (struct reply_info*)e->entry.data; + if(rep && rep->security > sec_status_bogus && + (!qstate->env->cfg->serve_expired_ttl || + qstate->env->cfg->serve_expired_ttl_reset || + *qstate->env->now <= rep->serve_expired_ttl)) { + verbose(VERB_ALGO, "validation failed but " + "previously cached valid response " + "exists; set serve-expired-norec-ttl " + "for response in cache"); + rep->serve_expired_norec_ttl = NORR_TTL + + *qstate->env->now; + if(qstate->env->cfg->serve_expired_ttl_reset && + *qstate->env->now + qstate->env->cfg->serve_expired_ttl + > rep->serve_expired_ttl) { + verbose(VERB_ALGO, "reset serve-expired-ttl for " + "valid response in cache"); + rep->serve_expired_ttl = *qstate->env->now + + qstate->env->cfg->serve_expired_ttl; + } + /* Return an error response. + * If serve-expired-client-timeout is enabled, + * the client-timeout logic will try to find an + * (expired) answer in the cache as last + * resort. If it is not enabled, expired + * answers are already used before the mesh + * activation. */ + qstate->return_rcode = LDNS_RCODE_SERVFAIL; + qstate->return_msg = NULL; + qstate->ext_state[id] = module_finished; + lock_rw_unlock(&e->entry.lock); + return 0; + } + lock_rw_unlock(&e->entry.lock); + } + vq->orig_msg->rep->ttl = ve->bogus_ttl; vq->orig_msg->rep->prefetch_ttl = PREFETCH_TTL_CALC(vq->orig_msg->rep->ttl); - vq->orig_msg->rep->serve_expired_ttl = + vq->orig_msg->rep->serve_expired_ttl = vq->orig_msg->rep->ttl + qstate->env->cfg->serve_expired_ttl; if((qstate->env->cfg->val_log_level >= 1 || qstate->env->cfg->log_servfail) && @@ -2518,8 +2561,9 @@ processFinished(struct module_qstate* qstate, struct val_qstate* vq, * to check if from parentNS */ if(!qstate->no_cache_store) { if(!dns_cache_store(qstate->env, &vq->orig_msg->qinfo, - vq->orig_msg->rep, 0, qstate->prefetch_leeway, 0, NULL, - qstate->query_flags, qstate->qstarttime)) { + vq->orig_msg->rep, 0, qstate->prefetch_leeway, + 0, qstate->region, qstate->query_flags, + qstate->qstarttime)) { log_err("out of memory caching validator results"); } } @@ -2527,7 +2571,7 @@ processFinished(struct module_qstate* qstate, struct val_qstate* vq, /* for a referral, store the verified RRsets */ /* and this does not get prefetched, so no leeway */ if(!dns_cache_store(qstate->env, &vq->orig_msg->qinfo, - vq->orig_msg->rep, 1, 0, 0, NULL, + vq->orig_msg->rep, 1, 0, 0, qstate->region, qstate->query_flags, qstate->qstarttime)) { log_err("out of memory caching validator results"); } From d88eeb4c32ff3c3f5039ef39b77ecd066089664e Mon Sep 17 00:00:00 2001 From: Yorgos Thessalonikefs Date: Tue, 24 Sep 2024 16:49:34 +0200 Subject: [PATCH 4/5] Changelog entry for #1143: - Merge #1143: Fix cache update when serve expired is used. Expired records are favored over resolution and validation failures when serve-expired is used. --- doc/Changelog | 3 +++ 1 file changed, 3 insertions(+) diff --git a/doc/Changelog b/doc/Changelog index 4c32cc38a..9cf000016 100644 --- a/doc/Changelog +++ b/doc/Changelog @@ -2,6 +2,9 @@ - Attempt to further fix doh_downstream_buffer_size.tdir flakiness. - More clear text for prefetch and minimal-responses in the unbound.conf man page. + - Merge #1143: Fix cache update when serve expired is used. Expired + records are favored over resolution and validation failures when + serve-expired is used. 23 September 2024: Wouter - Fix dns64 with prefetch that the prefetch is stored in cache. From 84eeb9b97cb9c28c136a8a27181b31526c5fea67 Mon Sep 17 00:00:00 2001 From: "W.C.A. Wijngaards" Date: Wed, 25 Sep 2024 11:16:46 +0200 Subject: [PATCH 5/5] - Fix #1144: [FR] log timestamps in ISO8601 format with timezone. This adds the option `log-time-iso: yes` that logs in ISO8601 format. --- doc/Changelog | 5 +++++ doc/example.conf.in | 4 ++++ doc/unbound.conf.5.in | 4 ++++ util/config_file.c | 6 ++++++ util/config_file.h | 2 ++ util/configlexer.lex | 1 + util/configparser.y | 13 +++++++++++-- util/log.c | 36 ++++++++++++++++++++++++++++++++++++ util/log.h | 6 ++++++ 9 files changed, 75 insertions(+), 2 deletions(-) diff --git a/doc/Changelog b/doc/Changelog index 9cf000016..9172b2199 100644 --- a/doc/Changelog +++ b/doc/Changelog @@ -1,3 +1,8 @@ +25 September 2024: Wouter + - Fix #1144: [FR] log timestamps in ISO8601 format with timezone. + This adds the option `log-time-iso: yes` that logs in ISO8601 + format. + 24 September 2024: Yorgos - Attempt to further fix doh_downstream_buffer_size.tdir flakiness. - More clear text for prefetch and minimal-responses in the diff --git a/doc/example.conf.in b/doc/example.conf.in index e5bb5029f..2d16ee75f 100644 --- a/doc/example.conf.in +++ b/doc/example.conf.in @@ -461,6 +461,10 @@ server: # print UTC timestamp in ascii to logfile, default is epoch in seconds. # log-time-ascii: no + # log timestamp in ISO8601 format if also log-time-ascii is enabled. + # (y-m-dTh:m:s.msec[+-]tzhours:tzminutes) + # log-time-iso: no + # print one line with time, IP, name, type, class for every query. # log-queries: no diff --git a/doc/unbound.conf.5.in b/doc/unbound.conf.5.in index d9c7f249a..bc48db478 100644 --- a/doc/unbound.conf.5.in +++ b/doc/unbound.conf.5.in @@ -936,6 +936,10 @@ Sets logfile lines to use a timestamp in UTC ascii. Default is no, which prints the seconds since 1970 in brackets. No effect if using syslog, in that case syslog formats the timestamp printed into the log files. .TP +.B log\-time\-iso:\fR +Log time in ISO8601 format, if \fBlog\-time\-ascii:\fR yes is also set. +Default is no. +.TP .B log\-queries: \fI Prints one line per query to the log, with the log timestamp and IP address, name, type and class. Default is no. Note that it takes time to print these diff --git a/util/config_file.c b/util/config_file.c index 3898a8b0a..2eb81fcee 100644 --- a/util/config_file.c +++ b/util/config_file.c @@ -138,6 +138,7 @@ config_create(void) cfg->use_syslog = 1; cfg->log_identity = NULL; /* changed later with argv[0] */ cfg->log_time_ascii = 0; + cfg->log_time_iso = 0; cfg->log_queries = 0; cfg->log_replies = 0; cfg->log_tag_queryreply = 0; @@ -547,6 +548,9 @@ int config_set_option(struct config_file* cfg, const char* opt, else if(strcmp(opt, "log-time-ascii:") == 0) { IS_YES_OR_NO; cfg->log_time_ascii = (strcmp(val, "yes") == 0); log_set_time_asc(cfg->log_time_ascii); } + else if(strcmp(opt, "log-time-iso:") == 0) + { IS_YES_OR_NO; cfg->log_time_iso = (strcmp(val, "yes") == 0); + log_set_time_iso(cfg->log_time_iso); } else S_SIZET_NONZERO("max-udp-size:", max_udp_size) else S_YNO("use-syslog:", use_syslog) else S_STR("log-identity:", log_identity) @@ -1066,6 +1070,7 @@ config_get_option(struct config_file* cfg, const char* opt, else O_YNO(opt, "use-syslog", use_syslog) else O_STR(opt, "log-identity", log_identity) else O_YNO(opt, "log-time-ascii", log_time_ascii) + else O_YNO(opt, "log-time-iso", log_time_iso) else O_DEC(opt, "num-threads", num_threads) else O_IFC(opt, "interface", num_ifs, ifs) else O_IFC(opt, "outgoing-interface", num_out_ifs, out_ifs) @@ -2413,6 +2418,7 @@ config_apply(struct config_file* config) USEFUL_SERVER_TOP_TIMEOUT = RTT_MAX_TIMEOUT; BLACKLIST_PENALTY = USEFUL_SERVER_TOP_TIMEOUT*4; log_set_time_asc(config->log_time_ascii); + log_set_time_iso(config->log_time_iso); autr_permit_small_holddown = config->permit_small_holddown; stream_wait_max = config->stream_wait_size; http2_query_buffer_max = config->http_query_buffer_size; diff --git a/util/config_file.h b/util/config_file.h index 29dd71620..fbb09aa62 100644 --- a/util/config_file.h +++ b/util/config_file.h @@ -341,6 +341,8 @@ struct config_file { int use_syslog; /** log timestamp in ascii UTC */ int log_time_ascii; + /** log timestamp in ISO8601 format */ + int log_time_iso; /** log queries with one line per query */ int log_queries; /** log replies with one line per reply */ diff --git a/util/configlexer.lex b/util/configlexer.lex index b4442e913..dbf2910de 100644 --- a/util/configlexer.lex +++ b/util/configlexer.lex @@ -431,6 +431,7 @@ permit-small-holddown{COLON} { YDVAR(1, VAR_PERMIT_SMALL_HOLDDOWN) } use-syslog{COLON} { YDVAR(1, VAR_USE_SYSLOG) } log-identity{COLON} { YDVAR(1, VAR_LOG_IDENTITY) } log-time-ascii{COLON} { YDVAR(1, VAR_LOG_TIME_ASCII) } +log-time-iso{COLON} { YDVAR(1, VAR_LOG_TIME_ISO) } log-queries{COLON} { YDVAR(1, VAR_LOG_QUERIES) } log-replies{COLON} { YDVAR(1, VAR_LOG_REPLIES) } log-tag-queryreply{COLON} { YDVAR(1, VAR_LOG_TAG_QUERYREPLY) } diff --git a/util/configparser.y b/util/configparser.y index dfc0c58af..2ca16f81c 100644 --- a/util/configparser.y +++ b/util/configparser.y @@ -207,7 +207,7 @@ extern struct config_parser_state* cfg_parser; %token VAR_HARDEN_UNKNOWN_ADDITIONAL VAR_DISABLE_EDNS_DO VAR_CACHEDB_NO_STORE %token VAR_LOG_DESTADDR VAR_CACHEDB_CHECK_WHEN_SERVE_EXPIRED %token VAR_COOKIE_SECRET_FILE VAR_ITER_SCRUB_NS VAR_ITER_SCRUB_CNAME -%token VAR_MAX_GLOBAL_QUOTA VAR_HARDEN_UNVERIFIED_GLUE +%token VAR_MAX_GLOBAL_QUOTA VAR_HARDEN_UNVERIFIED_GLUE VAR_LOG_TIME_ISO %% toplevelvars: /* empty */ | toplevelvars toplevelvar ; @@ -347,7 +347,7 @@ content_server: server_num_threads | server_verbosity | server_port | server_harden_unknown_additional | server_disable_edns_do | server_log_destaddr | server_cookie_secret_file | server_iter_scrub_ns | server_iter_scrub_cname | server_max_global_quota | - server_harden_unverified_glue + server_harden_unverified_glue | server_log_time_iso ; stub_clause: stubstart contents_stub { @@ -1250,6 +1250,15 @@ server_log_time_ascii: VAR_LOG_TIME_ASCII STRING_ARG free($2); } ; +server_log_time_iso: VAR_LOG_TIME_ISO STRING_ARG + { + OUTYY(("P(server_log_time_iso:%s)\n", $2)); + if(strcmp($2, "yes") != 0 && strcmp($2, "no") != 0) + yyerror("expected yes or no."); + else cfg_parser->cfg->log_time_iso = (strcmp($2, "yes")==0); + free($2); + } + ; server_log_queries: VAR_LOG_QUERIES STRING_ARG { OUTYY(("P(server_log_queries:%s)\n", $2)); diff --git a/util/log.c b/util/log.c index a15ee920c..a44758728 100644 --- a/util/log.c +++ b/util/log.c @@ -45,6 +45,7 @@ #ifdef HAVE_TIME_H #include #endif +#include #ifdef HAVE_SYSLOG_H # include #else @@ -81,6 +82,8 @@ static int logging_to_syslog = 0; #endif /* HAVE_SYSLOG_H */ /** print time in UTC or in secondsfrom1970 */ static int log_time_asc = 0; +/** print time in iso format */ +static int log_time_iso = 0; void log_init(const char* filename, int use_syslog, const char* chrootdir) @@ -205,6 +208,11 @@ void log_set_time_asc(int use_asc) log_time_asc = use_asc; } +void log_set_time_iso(int use_iso) +{ + log_time_iso = use_iso; +} + void* log_get_lock(void) { if(!key_created) @@ -269,6 +277,34 @@ log_vmsg(int pri, const char* type, lock_basic_unlock(&log_lock); return; } +#if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R) + if(log_time_iso && log_time_asc) { + char tzbuf[16]; + struct timeval tv; + struct tm tm, *tm_p; + if(gettimeofday(&tv, NULL) < 0) + memset(&tv, 0, sizeof(tv)); + now = (time_t)tv.tv_sec; + tm_p = localtime_r(&now, &tm); + strftime(tmbuf, sizeof(tmbuf), "%Y-%m-%dT%H:%M:%S", tm_p); + if(strftime(tzbuf, sizeof(tzbuf), "%z", tm_p) == 5) { + /* put ':' in "+hh:mm" */ + tzbuf[5] = tzbuf[4]; + tzbuf[4] = tzbuf[3]; + tzbuf[3] = ':'; + tzbuf[6] = 0; + } + fprintf(logfile, "%s.%3.3d%s %s[%d:%x] %s: %s\n", + tmbuf, (int)tv.tv_usec/1000, tzbuf, + ident, (int)getpid(), tid?*tid:0, type, message); +#ifdef UB_ON_WINDOWS + /* line buffering does not work on windows */ + fflush(logfile); +#endif + lock_basic_unlock(&log_lock); + return; + } +#endif /* HAVE_STRFTIME && HAVE_LOCALTIME_R */ now = (time_t)time(NULL); #if defined(HAVE_STRFTIME) && defined(HAVE_LOCALTIME_R) if(log_time_asc && strftime(tmbuf, sizeof(tmbuf), "%b %d %H:%M:%S", diff --git a/util/log.h b/util/log.h index 29a1ba380..e8b03c45a 100644 --- a/util/log.h +++ b/util/log.h @@ -138,6 +138,12 @@ void log_ident_set_or_default(const char* identity); */ void log_set_time_asc(int use_asc); +/** + * Set if the time value is printed in ISO8601 format. + * @param use_iso: if true, ascii timestamps are formatted in iso format. + */ +void log_set_time_iso(int use_iso); + /** get log lock */ void* log_get_lock(void);