Filterdns has stopped resolving hostnames in firewall aliases

[SteveITS]

I ran into a problem today where our office pfSense did not have the correct IP for a hostname in an alias.

Per the DNS Resolver log the last filterdns entry was March 20. There are no filterdns entries in the system log.

The "Unable to create monitoring thread" error is NOT being logged.

All the expected filterdns processes ARE running [per Diagnostics> System Activity], for each hostname:

20    0   111M    20M usem     2   0:09   0.00% /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1{example.net}
16827 root

Before I start restarting things, any idea where to look as to why it isn't resolving hostnames after March 20?

[SteveITS]

Sounds like https://redmine.pfsense.org/issues/8758 in particular the "Is" state:

root    62658   0.0  0.5 113276  20412  -  Is    4Feb25      1:59.64 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1

Similar to that one, if I "killall filterdns" and then Status>Filter Reload, the table is immediately updated. (for convenience "pfctl -T show -t aliasname" shows this at a command prompt)

FWIW that redmine links to https://redmine.pfsense.org/issues/9296
...but both are marked as closed/resolved. :(

[SteveITS]

Happened again. Two hostnames that resolve to the same valid/correct IP are not in the table in pfSense. The log lists both:

Adding Action: pf table: AliasName host: host.example.com
Adding Action: pf table: AliasName host: host2.example.net

...but they're not in the table until I do the killall and then a filter reload.

[SteveITS]

Just us? :( Any idea of what to look for in logs? Since I can't seem to find an error...

[Gertjan]

@SteveITS said in Filterdns has stopped resolving hostnames in firewall aliases:

the "Is" state:

Is = Interrupted, and sleeping - so it's waiting for 'something'.
So, just guessing : the main job is hammering the DNS subsystem, normally the Resolver, with DNS requests.
What if unbound, the resolver was restarted / stopped ? and filterdns missed that / doesn't time out, and is waiting (sleeping) forever ?

My questions boils down to : what happens with your unbound ? Does it restart a lot ? Look at the resolver log to find out.

I can't recall if there is a command that can be used to see what a process is waiting for. Some one knows ?

[SteveITS]

@Gertjan Unbound's been running since May 1 on this router. Not using DHCP registration, or even DHCP on this router.

unbound 19499   0.0  2.3 124144  92208  -  Ss    1May25     14:45.04 /usr/local/sbin/unbound -c /var/unbound/unbound.conf

One of Jim's comments in 8758 was, "The I state indicates it's sleeping for over 20 seconds and per-se is not the problem because filterdns threads sleep for 1 minute so it will stay as S in the first 20 seconds and then move to I." So that may just be a red herring.

I didn't write it above but the missing IP in question this time was my home, and I log in every single day. Also AFAICT the IP didn't change (no notification in pfSense). So the IP just disappeared from the table one day.

[SteveITS]

Happened again.

/var/etc/filterdns.conf contains hostnames and table names as expected.

: ps aux | grep dns
root    14880   0.0  0.2  20348   9672  -  S    Fri20       0:11.89 /usr/local/sbin/lighttpd_pfb -f /var/unbound/pfb_dnsbl_lighty.conf
root    29469   0.0  0.1  21872   3552  -  Is   Fri20       0:02.73 /usr/local/sbin/filterdns -p /var/run/filterdns-ipsec.pid -i 60 -c /var/etc/ipsec/filterdns-ipsec.hosts -d 1
root    64743   0.0  0.4  88956  17488  -  Is   Fri20       0:08.51 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    14206   0.0  0.1  13040   2656  0  S+   17:39       0:00.00 grep dns

The table in question has only one IP in it, not two.

"grep filterd resolver.log" shows "Adding Action: pf table:" for the missing hostname.

As above, I had to "killall filterdns" and then Status>Filter Reload to recover.

[SteveITS]

Still just us huh? :(

Today I was unable to connect because the table was missing the IP again. At 4 am pfSense logged several "failed to resolve host" errors (from various hostnames)...based on the time I expect a ISP outage which is not uncommon as they do overnight restarts.

To be a bit different I "edited" the alias to save without changes, and applied...logs do show the "Adding Action" entry for the hostname in question...but it is not added and the table still contains the 29 entries it did before that.

As above, I had to "killall filterdns" to recover and add the 30th IP to the table.

edit:
Also of note this IP has not changed recently...the point being it was removed from the pf table at some point.