The pfSense Store

Author Topic: filterdns stops working  (Read 27 times)

0 Members and 1 Guest are viewing this topic.

Offline Birke

  • Jr. Member
  • **
  • Posts: 56
  • Karma: +12/-0
    • View Profile
filterdns stops working
« on: Yesterday at 10:57:00 am »
hi,

i have a 2.4.2 pfsense with suricata and pfblockerng (i updated recently to the 2.4.2 release, before it was 2.3.4).

the problem is, that filterdns stops updating the aliases.

i have aliases like:
google: 64.233.160.0/19, 66.102.0.0/20, 66.249.64.0/19, 72.14.192.0/18, 74.125.0.0/16, 209.85.128.0/17, 216.239.32.0/19, 173.194.0.0/16, 172.217.0.0/16, 216.58.192.0/19
timeserver: 130.149.17.21, 192.53.103.103, 192.53.103.104, 192.53.103.108
heise: heise.de
allowlist: google, timeserver, heise

then i have a firewall-rule that will allow traffic to everything in alias allowlist.
that works like intended, but after some time the filterdns stops updating the aliases. if heise.de changes its ip, the entry in the table stays on the old ip.
if i enter a new ip-alias with an url and make a rule with it, it wont resolve the url. the according table of the alias stays empty.

the dns resolver log only shows:
Code: [Select]
Dec 12 12:45:04 gw-wg filterdns: clearing entry 10.1.4.55 from pf table C84975_61 on host c84975-61.prokas2.birken.pk2
Dec 12 12:45:04 gw-wg filterdns: clearing entry 2606:2800:234:660:118e:28f:1d8a:2522 from pf table Deny on host fast.fonts.net
Dec 12 12:45:04 gw-wg filterdns: clearing entry 68.232.35.182 from pf table Deny on host fast.fonts.net
Dec 12 12:45:04 gw-wg filterdns: clearing entry 104.96.38.230 from pf table Deny on host static.etracker.com
Dec 12 12:45:04 gw-wg filterdns: clearing entry 62.201.164.117 from pf table Deny on host www.etracker.de
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: service stopped (unbound 1.6.6).
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 0: 89 queries, 15 answers from cache, 74 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 0: requestlist max 8 avg 1.48649 exceeded 0 jostled 0
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: average recursion processing time 0.028766 sec
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: [25%]=0.00840758 median[50%]=0.016384 [75%]=0.0469675
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000000    0.000001 12
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000256    0.000512 4
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000512    0.001024 2
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.008192    0.016384 19
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.016384    0.032768 12
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.032768    0.065536 15
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.065536    0.131072 9
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.131072    0.262144 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 1: 17 queries, 0 answers from cache, 17 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 1: requestlist max 2 avg 0.176471 exceeded 0 jostled 0
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: average recursion processing time 0.038271 sec
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: [25%]=0.0200704 median[50%]=0.0270336 [75%]=0.045056
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000000    0.000001 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.008192    0.016384 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.016384    0.032768 10
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.032768    0.065536 2
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.065536    0.131072 3
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 2: 101 queries, 18 answers from cache, 83 recursions, 1 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 2: requestlist max 5 avg 0.369048 exceeded 0 jostled 0
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: average recursion processing time 0.039225 sec
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: [25%]=0.0122027 median[50%]=0.0230156 [75%]=0.049664
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000000    0.000001 8
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000256    0.000512 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.008192    0.016384 24
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.016384    0.032768 21
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.032768    0.065536 16
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.065536    0.131072 8
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.131072    0.262144 4
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.262144    0.524288 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 3: 41 queries, 2 answers from cache, 39 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: server stats for thread 3: requestlist max 1 avg 0.25641 exceeded 0 jostled 0
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: average recursion processing time 3.871467 sec
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: [25%]=0.0121417 median[50%]=0.02048 [75%]=0.04096
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000000    0.000001 2
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.000256    0.000512 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.008192    0.016384 14
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.016384    0.032768 10
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.032768    0.065536 9
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:    0.065536    0.131072 2
Dec 12 12:52:51 gw-wg unbound: [49198:0] info:  128.000000  256.000000 1
Dec 12 12:52:51 gw-wg unbound: [49198:0] notice: Restart of unbound 1.6.6.
Dec 12 12:52:51 gw-wg unbound: [49198:0] notice: init module 0: validator
Dec 12 12:52:51 gw-wg unbound: [49198:0] notice: init module 1: iterator
Dec 12 12:52:51 gw-wg unbound: [49198:0] info: start of service (unbound 1.6.6).
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: service stopped (unbound 1.6.6).
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 0: 11 queries, 0 answers from cache, 11 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 0: requestlist max 2 avg 0.272727 exceeded 0 jostled 0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: average recursion processing time 0.039542 sec
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: [25%]=0.022528 median[50%]=0.04096 [75%]=0.0559787
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.000000    0.000001 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.008192    0.016384 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.016384    0.032768 2
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.032768    0.065536 6
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.065536    0.131072 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 1: 3 queries, 0 answers from cache, 3 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: average recursion processing time 0.112245 sec
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: [25%]=0 median[50%]=0 [75%]=0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.065536    0.131072 2
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.131072    0.262144 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 2: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 2: requestlist max 0 avg 0 exceeded 0 jostled 0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: average recursion processing time 0.101974 sec
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: [25%]=0 median[50%]=0 [75%]=0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.065536    0.131072 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 3: 6 queries, 1 answers from cache, 5 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: server stats for thread 3: requestlist max 0 avg 0 exceeded 0 jostled 0
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: average recursion processing time 0.049375 sec
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: histogram of recursion processing times
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: [25%]=0.02048 median[50%]=0.049152 [75%]=0.090112
Dec 12 12:54:17 gw-wg unbound: [49198:0] info: lower(secs) upper(secs) recursions
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.008192    0.016384 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.016384    0.032768 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.032768    0.065536 1
Dec 12 12:54:17 gw-wg unbound: [49198:0] info:    0.065536    0.131072 2
Dec 12 12:54:17 gw-wg unbound: [49198:0] notice: Restart of unbound 1.6.6.
the first lines show the last working filterdns entries. after that it only repeats the last part.
system.log doesnt show anything at that time.

if i (re)start the filterdns manually with /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1 then everything works again for some time.
the Firewall Maximum Table Entries is set to 6000000.
i also tried to change the dns-servers with 127.0.0.1 as first server, but that also didn't help.

any clues what i could check/change to resolve this problem?