Doctor! Doctor! It hurts when I stick a knife in here!
When you do weird, harsh, or unrealistic packet filtering, application
software will occasionally log that you are losing packets which should
not be filtered, to alert that normal network operation isn't occuring.
That is to be expected. It is even desirable.
So I think you are only thinking of your own usage case, and trying
too hard to show that it is synthetic.
But let's get back to the real story: libunbound is upstream software.
We carry diffs against upstream software, but only when the case is
extremely compelling.
So how about taking your case up with those doctors, instead.
Peter J. Philipp <p...@delphinusdns.org> wrote:
> On Fri, Apr 14, 2023 at 05:18:33PM +0200, Florian Obser wrote:
> > Sorry, this doesn't make any sense.
> >
> > I could never reproduce the -1 or > 65535 case reliably, I see it once
> > in a while, but I can't trigger it. I also can't reproduce it with your
> > instructions.
> >
> > As far as I can work out these weird answer_len numbers come from
> > libworker_event_done_cb() in libworker.c, specifically:
> >
> > (*cb)(cb_arg, rcode, (buf?(void*)sldns_buffer_begin(buf):NULL),
> > (buf?(int)sldns_buffer_limit(buf):0), sec, why_bogus,
> > was_ratelimited);
> >
> > So you are comparing against sldns_buffer_limit(buf), that can just be
> > anything, you can't derive from that "remote server had no listening
> > port".
> >
> > I get "rcode: 2, answer_len: 128" or something else sensibly if I point
> > unwind at a non-responsive forwarder.
> >
> > Since you can reproduce it, can you try this diff please and report
> > back?
> >
> > Does it hit that code path when answer_len is -1 or when answer_len
> > is 65552?
>
> Hi Florian,
>
> In earlier mails (in this thread) I think I showed a pf.conf entry that I
> used to make unwind only hit my forwarder. Again I killed it before this
> trial. In fact I had to do the trial twice since it didn't log in syslog.
>
> root@polarstern# unwind -d -vvvv 2>&1 | grep answer_len
>
> [1681487082] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487082] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487083] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487083] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487085] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487086] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487089] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487090] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487098] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487099] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487100] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 65552
> [1681487114] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 128
> [1681487115] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 28
> [1681487118] libunbound[90786:0] warning: libworker_event_done_cb: rcode: 2,
> answer_len: 65552
> ...
>
> That's again after I pinged centroid.eu with the forwarding nameserver off. I
> couldn't get it to reply -1, I could not reproduce a "too short" message even
> though I saw permission denied (error 13) in a ktrace. And it didn't
> hit that code path...
>
> You know what the second (most recent) patch I sent was bad too I just
> realised. It didn't cover all the "too short" instances like the first
> patch did. For that I'm sorry. It was covered in:
> Message-ID: <438f75c61b9ef...@stern.delphinusdns.org>
>
> Best Regards,
> -peter
>
> > diff --git libunbound/libunbound/libworker.c
> > libunbound/libunbound/libworker.c
> > index 11bf5f9db55..6bb34001ee9 100644
> > --- libunbound/libunbound/libworker.c
> > +++ libunbound/libunbound/libworker.c
> > @@ -680,6 +680,9 @@ libworker_event_done_cb(void* arg, int rcode,
> > sldns_buffer* buf,
> > context_query_delete(q);
> > lock_basic_unlock(&ctx->cfglock);
> >
> > + log_warn("%s: rcode: %d, answer_len: %d\n", __func__,
> > + rcode, buf?(int)sldns_buffer_limit(buf):0);
> > +
> > if(!cancelled) {
> > /* call callback */
> > int sec = 0;
> >
> >
> > >
> > > ---------------->
> > > Apr 13 20:53:26 polarstern unwind[73363]: terminating
> > > Apr 13 20:53:27 polarstern resolvd[81113]: rebuilding: new unwind
> > > Apr 13 20:54:12 polarstern unwind[16252]: remote nameserver had no
> > > listening port: centroid.eu. IN A
> > > ^Z[1] + Suspended tail -f /var/log/daemon
> > > root@polarstern# dddctl start
> > > starting delphinusdnsd
> > > root@polarstern# fg
> > > tail -f /var/log/daemon
> > > <----------------
> > > (after this restart of delphinusdnsd forwarder this pinged fine, no more
> > > logs)
> > >
> > > The patch is below my .signature,
> > >
> > > Best Regards,
> > > -peter
> > >
> > > Index: resolver.c
> > > ===================================================================
> > > RCS file: /cvs/src/sbin/unwind/resolver.c,v
> > > retrieving revision 1.158
> > > diff -u -p -u -r1.158 resolver.c
> > > --- resolver.c 8 Feb 2023 08:01:25 -0000 1.158
> > > +++ resolver.c 13 Apr 2023 18:51:01 -0000
> > > @@ -954,13 +954,19 @@ resolve_done(struct uw_resolver *res, vo
> > > running_res = --rq->running;
> > >
> > > if (answer_len < LDNS_HEADER_SIZE) {
> > > - log_warnx("bad packet: too short");
> > > + if (answer_len != -1)
> > > + log_warnx("bad packet: too short");
> > > goto servfail;
> > > }
> > >
> > > if (answer_len > UINT16_MAX) {
> > > - log_warnx("bad packet: too large: %d - %s", answer_len,
> > > - query_imsg2str(query_imsg));
> > > + if (answer_len == 65552) {
> > > + log_warnx("remote nameserver had no listening port: %s",
> > > + query_imsg2str(query_imsg);
> > > + } else {
> > > + log_warnx("bad packet: too large: %d - %s", answer_len,
> > > + query_imsg2str(query_imsg));
> > > + }
> > > goto servfail;
> > > }
> > > answer_header->answer_len = answer_len;
> > >
> >
> > --
> > In my defence, I have been left unsupervised.
>
