- Add that log-servfail prints an IP address and more information

  about one of the last failures for that query.

diff --git a/doc/Changelog b/doc/Changelog
index 35ee6786fbd6f06d286fd97e6873278f6fff5d8b..6f1b4c3a2755162e6011380a5ef754e26331d014 100644 (file)
--- a/doc/Changelog
+++ b/doc/Changelog
@@ -1,3 +1,7 @@
+29 April 2021: Wouter
+       - Add that log-servfail prints an IP address and more information
+         about one of the last failures for that query.
+
 28 April 2021: George
        - Fix compiler warning for signed/unsigned comparison for
          max_reuse_tcp_queries.

diff --git a/ipsecmod/ipsecmod.c b/ipsecmod/ipsecmod.c
index e443e882b5c8c569384270d2e9f14f563f5f4d01..e42af6f497ea5d30a5eee962787acfd7b393613b 100644 (file)
--- a/ipsecmod/ipsecmod.c
+++ b/ipsecmod/ipsecmod.c
@@ -419,6 +419,7 @@ ipsecmod_handle_query(struct module_qstate* qstate,
                        if(!qstate->env->cfg->ipsecmod_ignore_bogus &&
                                rrset_data->security == sec_status_bogus) {
                                log_err("ipsecmod: bogus IPSECKEY");
+                               errinf(qstate, "ipsecmod: bogus IPSECKEY");
                                ipsecmod_error(qstate, id);
                                return;
                        }
@@ -426,6 +427,7 @@ ipsecmod_handle_query(struct module_qstate* qstate,
                        if(!call_hook(qstate, iq, ie) &&
                                qstate->env->cfg->ipsecmod_strict) {
                                log_err("ipsecmod: ipsecmod-hook failed");
+                               errinf(qstate, "ipsecmod: ipsecmod-hook failed");
                                ipsecmod_error(qstate, id);
                                return;
                        }
@@ -497,6 +499,7 @@ ipsecmod_handle_response(struct module_qstate* qstate,
                        qstate->qinfo.qname_len, LDNS_RR_TYPE_IPSECKEY,
                        qstate->qinfo.qclass, 0)) {
                        log_err("ipsecmod: could not generate subquery.");
+                       errinf(qstate, "ipsecmod: could not generate subquery.");
                        ipsecmod_error(qstate, id);
                }
                return;
@@ -520,6 +523,7 @@ ipsecmod_operate(struct module_qstate* qstate, enum module_ev event, int id,
        if((event == module_event_new || event == module_event_pass) &&
                iq == NULL) {
                if(!ipsecmod_new(qstate, id)) {
+                       errinf(qstate, "ipsecmod: could not ipsecmod_new");
                        ipsecmod_error(qstate, id);
                        return;
                }
@@ -542,6 +546,7 @@ ipsecmod_operate(struct module_qstate* qstate, enum module_ev event, int id,
        }
        if(event == module_event_error) {
                verbose(VERB_ALGO, "got called with event error, giving up");
+               errinf(qstate, "ipsecmod: got called with event error");
                ipsecmod_error(qstate, id);
                return;
        }
@@ -552,6 +557,7 @@ ipsecmod_operate(struct module_qstate* qstate, enum module_ev event, int id,
        }
 
        log_err("ipsecmod: bad event %s", strmodulevent(event));
+       errinf(qstate, "ipsecmod: operate got bad event");
        ipsecmod_error(qstate, id);
        return;
 }

diff --git a/iterator/iterator.c b/iterator/iterator.c
index 0f662304d345270e3d8ea4e1bbcd4176362ff227..f0105ad4b085dee5216eb63b05c7031ffd80d910 100644 (file)
--- a/iterator/iterator.c
+++ b/iterator/iterator.c
@@ -585,6 +585,60 @@ handle_cname_response(struct module_qstate* qstate, struct iter_qstate* iq,
        return 1;
 }
 
+/** add response specific error information for log servfail */
+static void
+errinf_reply(struct module_qstate* qstate, struct iter_qstate* iq)
+{
+       if(qstate->env->cfg->val_log_level < 2 && !qstate->env->cfg->log_servfail)
+               return;
+       if((qstate->reply && qstate->reply->addrlen != 0) ||
+               (iq->fail_reply && iq->fail_reply->addrlen != 0)) {
+               char from[256], frm[512];
+               if(qstate->reply && qstate->reply->addrlen != 0)
+                       addr_to_str(&qstate->reply->addr, qstate->reply->addrlen,
+                               from, sizeof(from));
+               else
+                       addr_to_str(&iq->fail_reply->addr, iq->fail_reply->addrlen,
+                               from, sizeof(from));
+               snprintf(frm, sizeof(frm), "from %s", from);
+               errinf(qstate, frm);
+       }
+       if(iq->scrub_failures || iq->parse_failures) {
+               if(iq->scrub_failures)
+                       errinf(qstate, "upstream response failed scrub");
+               if(iq->parse_failures)
+                       errinf(qstate, "could not parse upstream response");
+       } else if(iq->response == NULL && iq->timeout_count != 0) {
+               errinf(qstate, "upstream server timeout");
+       } else if(iq->response == NULL) {
+               errinf(qstate, "no server to query");
+               if(iq->dp) {
+                       if(iq->dp->target_list == NULL)
+                               errinf(qstate, "no addresses for nameservers");
+                       else    errinf(qstate, "nameserver addresses not usable");
+                       if(iq->dp->nslist == NULL)
+                               errinf(qstate, "have no nameserver names");
+                       if(iq->dp->bogus)
+                               errinf(qstate, "NS record was dnssec bogus");
+               }
+       }
+       if(iq->response && iq->response->rep) {
+               if(FLAGS_GET_RCODE(iq->response->rep->flags) != 0) {
+                       char rcode[256], rc[32];
+                       (void)sldns_wire2str_rcode_buf(
+                               FLAGS_GET_RCODE(iq->response->rep->flags),
+                               rc, sizeof(rc));
+                       snprintf(rcode, sizeof(rcode), "got %s", rc);
+                       errinf(qstate, rcode);
+               } else {
+                       /* rcode NOERROR */
+                       if(iq->response->rep->an_numrrsets == 0) {
+                               errinf(qstate, "nodata answer");
+                       }
+               }
+       }
+}
+
 /** see if last resort is possible - does config allow queries to parent */
 static int
 can_have_last_resort(struct module_env* env, uint8_t* nm, size_t nmlen,
@@ -1922,6 +1976,7 @@ processLastResort(struct module_qstate* qstate, struct iter_qstate* iq,
                 * of a response. */
                errinf(qstate, "all the configured stub or forward servers failed,");
                errinf_dname(qstate, "at zone", iq->dp->name);
+               errinf_reply(qstate, iq);
                verbose(VERB_QUERY, "configured stub or forward servers failed -- returning SERVFAIL");
                return error_response_cache(qstate, id, LDNS_RCODE_SERVFAIL);
        }
@@ -2068,6 +2123,7 @@ processLastResort(struct module_qstate* qstate, struct iter_qstate* iq,
 
        errinf(qstate, "all servers for this domain failed,");
        errinf_dname(qstate, "at zone", iq->dp->name);
+       errinf_reply(qstate, iq);
        verbose(VERB_QUERY, "out of query targets -- returning SERVFAIL");
        /* fail -- no more targets, no more hope of targets, no hope 
         * of a response. */
@@ -2959,6 +3015,8 @@ processQueryResponse(struct module_qstate* qstate, struct iter_qstate* iq,
                        qstate->env->detach_subs));
                (*qstate->env->detach_subs)(qstate);
                iq->num_target_queries = 0;
+               iq->response = NULL;
+               iq->fail_reply = NULL;
                verbose(VERB_ALGO, "cleared outbound list for next round");
                return next_state(iq, QUERYTARGETS_STATE);
        } else if(type == RESPONSE_TYPE_CNAME) {
@@ -3722,6 +3780,7 @@ process_response(struct module_qstate* qstate, struct iter_qstate* iq,
        }
 
        /* parse message */
+       iq->fail_reply = qstate->reply;
        prs = (struct msg_parse*)regional_alloc(qstate->env->scratch, 
                sizeof(struct msg_parse));
        if(!prs) {
@@ -3735,12 +3794,15 @@ process_response(struct module_qstate* qstate, struct iter_qstate* iq,
        sldns_buffer_set_position(pkt, 0);
        if(parse_packet(pkt, prs, qstate->env->scratch) != LDNS_RCODE_NOERROR) {
                verbose(VERB_ALGO, "parse error on reply packet");
+               iq->parse_failures++;
                goto handle_it;
        }
        /* edns is not examined, but removed from message to help cache */
        if(parse_extract_edns(prs, &edns, qstate->env->scratch) !=
-               LDNS_RCODE_NOERROR)
+               LDNS_RCODE_NOERROR) {
+               iq->parse_failures++;
                goto handle_it;
+       }
 
        /* Copy the edns options we may got from the back end */
        if(edns.opt_list) {
@@ -3774,6 +3836,7 @@ process_response(struct module_qstate* qstate, struct iter_qstate* iq,
                        iq->num_current_queries--;
                        verbose(VERB_DETAIL, "Capsforid: scrub failed, starting fallback with no response");
                }
+               iq->scrub_failures++;
                goto handle_it;
        }
 

diff --git a/iterator/iterator.h b/iterator/iterator.h
index 342ac207e826b0fe77d852eba63f065849834366..7952f26df6c9f5da32f8bef8c00e285c82e2d577 100644 (file)
--- a/iterator/iterator.h
+++ b/iterator/iterator.h
@@ -406,6 +406,12 @@ struct iter_qstate {
        int auth_zone_response;
        /** True if the auth_zones should not be consulted for the query */
        int auth_zone_avoid;
+       /** true if there have been scrubbing failures of reply packets */
+       int scrub_failures;
+       /** true if there have been parse failures of reply packets */
+       int parse_failures;
+       /** a failure printout address for last received answer */
+       struct comm_reply* fail_reply;
 };
 
 /**

diff --git a/testcode/testbound.c b/testcode/testbound.c
index 5e10779fcdea991e638000c43063985977b807e2..a7cf27a73ea683c1a71704114da60642def05b71 100644 (file)
--- a/testcode/testbound.c
+++ b/testcode/testbound.c
@@ -279,6 +279,7 @@ setup_config(FILE* in, int* lineno, int* pass_argc, char* pass_argv[])
        fprintf(cfg, "          username: \"\"\n");
        fprintf(cfg, "          pidfile: \"\"\n");
        fprintf(cfg, "          val-log-level: 2\n");
+       fprintf(cfg, "          log-servfail: yes\n");
        fprintf(cfg, "remote-control:   control-enable: no\n");
        while(fgets(line, MAX_LINE_LEN-1, in)) {
                parse = line;