pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!
-
Hi,
I'm on pfSense 2.4.5 and pfBlockerNG 3.0.0.8.
After enabling the Unbound python mode for DNSBL and doing the Force Reload-DNSBL Unbound Resolver was stopped and did not start again.
I found the following information in the pfBlocker logfile:
| ...
| Starting Unbound Resolver... Not completed. [ 01/22/21 15:41:10 ]
| error: SSL handshake failed
| ...Saving DNSBL statistics... completed [ 01/22/21 15:41:05 ] ------------------------------------------------------------------------ Assembling DNSBL database...... completed [ 01/22/21 15:41:07 ] Added DNSBL Unbound python integration settings Adding DNSBL Unbound python mounts: Creating: /var/unbound/usr/local/bin Mounting: /usr/local/bin Creating: /var/unbound/usr/local/lib Mounting: /usr/local/lib Removing DNSBL SafeSearch mode (Resolver adv. setting) DNS Resolver ( enabled ) unbound.conf modifications: Added DNSBL Unbound Python mode Removed DNSBL SafeSearch mode Added DNSBL Unbound Python mode script Saving new DNSBL web server configuration to port [ 8081 and 8443 ] Stop Service DNSBL VIP address(es) configured Restarting DNSBL Service Stopping Unbound Resolver Unbound stopped in 1 sec. Starting Unbound Resolver... Not completed. [ 01/22/21 15:41:10 ] error: SSL handshake failed Restarting DNSBL Service (DNSBL python) DNSBL update [ 143616 | PASSED ]... completed ------------------------------------------------------------------------ ===[ GeoIP Process ]============================================ ===[ IPv4 Process ]================================================= [ Abuse_Feodo_C2_v4 ] Reload . completed .. ------------------------------ Original Master Final ------------------------------ 1337 1337 1337 [ Pass ]**** ----------------------------------------------------------------- [ Abuse_IPBL_v4 ] Reload . completed .. Empty file, Adding '127.1.7.7' to avoid download failure. ------------------------------ Original Master Final ------------------------------ 0 1 1 [ Pass ] ----------------------------------------------------------------- [ Abuse_SSLBL_v4 ] Reload . completed .. ------------------------------ Original Master Final ------------------------------ 123 109 109 [ Pass ] ----------------------------------------------------------------- [ BBC_C2_v4 ] Downloading update [ 01/22/21 15:41:11 ] . cURL Error: 28 Resolving timed out after 15001 milliseconds Retry in 5 seconds... . cURL Error: 28 Resolving timed out after 15000 milliseconds Retry in 5 seconds... . cURL Error: 28 Resolving timed out after 15003 milliseconds Retry in 5 seconds... .. unknown http status code | 0
(Re-)starting Unbound Resolver under Services/DNS Resolver/General Settings is also not possible. I get the rerror
| can't open file pfb_unbound.py for readingJan 22 15:47:55 unbound 77509:0 fatal error: failed to setup modules Jan 22 15:47:55 unbound 77509:0 error: module init for module python failed Jan 22 15:47:55 unbound 77509:0 error: pythonmod: can't open file pfb_unbound.py for reading Jan 22 15:47:55 unbound 77509:0 notice: init module 0: python Jan 22 15:47:15 filterdns failed to resolve host pool.ntp.org will retry later again. Jan 22 15:47:15 filterdns failed to resolve host time.windows.com will retry later again. Jan 22 15:47:15 filterdns failed to resolve host time.nist.gov will retry later again. Jan 22 15:45:15 filterdns failed to resolve host pool.ntp.org will retry later again. Jan 22 15:45:04 filterdns merge_config: configuration reload Jan 22 15:44:15 filterdns failed to resolve host time.windows.com will retry later again. Jan 22 15:44:15 filterdns failed to resolve host time-nw.nist.gov will retry later again. Jan 22 15:44:15 filterdns failed to resolve host time-b.nist.gov will retry later again. Jan 22 15:44:15 filterdns failed to resolve host time.nist.gov will retry later again. Jan 22 15:44:15 filterdns failed to resolve host pool.ntp.org will retry later again. Jan 22 15:44:15 filterdns failed to resolve host time-a.nist.gov will retry later again. Jan 22 15:43:15 filterdns failed to resolve host time-nw.nist.gov will retry later again. Jan 22 15:43:15 filterdns failed to resolve host time.windows.com will retry later again. Jan 22 15:43:15 filterdns failed to resolve host time-b.nist.gov will retry later again. Jan 22 15:43:15 filterdns failed to resolve host time.nist.gov will retry later again. Jan 22 15:43:15 filterdns failed to resolve host time-a.nist.gov will retry later again. Jan 22 15:43:15 filterdns failed to resolve host pool.ntp.org will retry later again. Jan 22 15:42:15 filterdns failed to resolve host time-nw.nist.gov will retry later again. Jan 22 15:42:15 filterdns failed to resolve host time.windows.com will retry later again. Jan 22 15:42:15 filterdns failed to resolve host time-b.nist.gov will retry later again. Jan 22 15:42:14 filterdns failed to resolve host pool.ntp.org will retry later again. Jan 22 15:42:14 filterdns failed to resolve host time-a.nist.gov will retry later again. Jan 22 15:42:14 filterdns failed to resolve host time.nist.gov will retry later again. Jan 22 15:41:10 unbound 38108:0 notice: init module 0: python Jan 22 15:41:09 unbound 61187:0 info: 2.000000 4.000000 5 Jan 22 15:41:09 unbound 61187:0 info: 1.000000 2.000000 2 Jan 22 15:41:09 unbound 61187:0 info: 0.524288 1.000000 5 Jan 22 15:41:09 unbound 61187:0 info: 0.131072 0.262144 3 Jan 22 15:41:09 unbound 61187:0 info: 0.032768 0.065536 2 Jan 22 15:41:09 unbound 61187:0 info: 0.016384 0.032768 2 Jan 22 15:41:09 unbound 61187:0 info: 0.008192 0.016384 1 Jan 22 15:41:09 unbound 61187:0 info: lower(secs) upper(secs) recursions Jan 22 15:41:09 unbound 61187:0 info: [25%]=0.065536 median[50%]=0.714573 [75%]=2 Jan 22 15:41:09 unbound 61187:0 info: histogram of recursion processing times Jan 22 15:41:09 unbound 61187:0 info: average recursion processing time 0.996802 sec Jan 22 15:41:09 unbound 61187:0 info: server stats for thread 1: requestlist max 36 avg 6.6 exceeded 0 jostled 0 Jan 22 15:41:09 unbound 61187:0 info: server stats for thread 1: 26 queries, 6 answers from cache, 20 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 15:41:09 unbound 61187:0 info: 1.000000 2.000000 1 Jan 22 15:41:09 unbound 61187:0 info: 0.524288 1.000000 2 Jan 22 15:41:09 unbound 61187:0 info: 0.262144 0.524288 2 Jan 22 15:41:09 unbound 61187:0 info: 0.016384 0.032768 3 Jan 22 15:41:09 unbound 61187:0 info: 0.008192 0.016384 2 Jan 22 15:41:09 unbound 61187:0 info: lower(secs) upper(secs) recursions Jan 22 15:41:09 unbound 61187:0 info: [25%]=0.0191147 median[50%]=0.032768 [75%]=0.643216 Jan 22 15:41:09 unbound 61187:0 info: histogram of recursion processing times Jan 22 15:41:09 unbound 61187:0 info: average recursion processing time 0.391598 sec Jan 22 15:41:09 unbound 61187:0 info: server stats for thread 0: requestlist max 8 avg 3.3 exceeded 0 jostled 0 Jan 22 15:41:09 unbound 61187:0 info: server stats for thread 0: 12 queries, 2 answers from cache, 10 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 15:41:09 unbound 61187:0 info: service stopped (unbound 1.10.1). Jan 22 15:40:15 unbound 61187:0 info: generate keytag query _ta-4f66. NULL IN Jan 22 15:40:15 unbound 61187:1 info: generate keytag query _ta-4f66. NULL IN Jan 22 15:40:09 unbound 61187:0 info: start of service (unbound 1.10.1). Jan 22 15:40:09 unbound 61187:0 notice: init module 1: iterator Jan 22 15:40:09 unbound 61187:0 notice: init module 0: validator Jan 22 15:40:02 unbound 44212:0 info: 4.000000 8.000000 1 Jan 22 15:40:02 unbound 44212:0 info: 2.000000 4.000000 3 Jan 22 15:40:02 unbound 44212:0 info: 1.000000 2.000000 17 Jan 22 15:40:02 unbound 44212:0 info: 0.524288 1.000000 43 Jan 22 15:40:02 unbound 44212:0 info: 0.262144 0.524288 144 Jan 22 15:40:02 unbound 44212:0 info: 0.131072 0.262144 146 Jan 22 15:40:02 unbound 44212:0 info: 0.065536 0.131072 116 Jan 22 15:40:02 unbound 44212:0 info: 0.032768 0.065536 71 Jan 22 15:40:02 unbound 44212:0 info: 0.016384 0.032768 287 Jan 22 15:40:02 unbound 44212:0 info: 0.008192 0.016384 132 Jan 22 15:40:02 unbound 44212:0 info: 0.004096 0.008192 8 Jan 22 15:40:02 unbound 44212:0 info: 0.000000 0.000001 39 Jan 22 15:40:02 unbound 44212:0 info: lower(secs) upper(secs) recursions Jan 22 15:40:02 unbound 44212:0 info: [25%]=0.0205371 median[50%]=0.050075 [75%]=0.222867 Jan 22 15:40:02 unbound 44212:0 info: histogram of recursion processing times Jan 22 15:40:02 unbound 44212:0 info: average recursion processing time 0.167938 sec Jan 22 15:40:02 unbound 44212:0 info: server stats for thread 1: requestlist max 26 avg 1.89474 exceeded 0 jostled 0 Jan 22 15:40:02 unbound 44212:0 info: server stats for thread 1: 2826 queries, 1819 answers from cache, 1007 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 15:40:02 unbound 44212:0 info: 2.000000 4.000000 3 Jan 22 15:40:02 unbound 44212:0 info: 1.000000 2.000000 13 Jan 22 15:40:02 unbound 44212:0 info: 0.524288 1.000000 29 Jan 22 15:40:02 unbound 44212:0 info: 0.262144 0.524288 49 Jan 22 15:40:02 unbound 44212:0 info: 0.131072 0.262144 68 Jan 22 15:40:02 unbound 44212:0 info: 0.065536 0.131072 59 Jan 22 15:40:02 unbound 44212:0 info: 0.032768 0.065536 48 Jan 22 15:40:02 unbound 44212:0 info: 0.016384 0.032768 167 Jan 22 15:40:02 unbound 44212:0 info: 0.008192 0.016384 52 Jan 22 15:40:02 unbound 44212:0 info: 0.004096 0.008192 1 Jan 22 15:40:02 unbound 44212:0 info: 0.000000 0.000001 24 Jan 22 15:40:02 unbound 44212:0 info: lower(secs) upper(secs) recursions Jan 22 15:40:02 unbound 44212:0 info: [25%]=0.021412 median[50%]=0.0413013 [75%]=0.196126 Jan 22 15:40:02 unbound 44212:0 info: histogram of recursion processing times Jan 22 15:40:02 unbound 44212:0 info: average recursion processing time 0.167664 sec Jan 22 15:40:02 unbound 44212:0 info: server stats for thread 0: requestlist max 29 avg 1.26511 exceeded 0 jostled 0 Jan 22 15:40:02 unbound 44212:0 info: server stats for thread 0: 1484 queries, 971 answers from cache, 513 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 15:40:02 unbound 44212:0 info: service stopped (unbound 1.10.1).
Any ideas about this problem?
Regards Jürgen
-
@cantor Reboot your box
-
@bbcan177 said in pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!:
@cantor Reboot your box
Doesn't work. Unbound is still down after reboot and can only be restarted after I uncheck the option "Eable Python Module".
-
@cantor
Increase the Resolver Log Level to "2", Save/Apply. Do you see any errors? -
@bbcan177 said in pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!:
@cantor
Increase the Resolver Log Level to "2", Save/Apply.Do you mean "Raw FilterLogs"? If not, where can I change the log level to level "2"?
Regards
Jürgen -
@cantor said in pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!:
Do you mean "Raw FilterLogs"? If not, where can I change the log level to level "2"?
pfSense > DNS Resolver > Adv Settings > Log Level > 2
-
-
pfBlockerNG
a) Change Unbound -> Unbound python mode
b) Save
c) Force Reload All
d) Reload hangs when restarting Unbound Resolver -
Switching to DNS Resolver tab after click on the logout button
a) Start service
b) Service does not start
Resolver log:
Jan 22 22:08:52 unbound: [44037:0] fatal error: failed to setup modules Jan 22 22:08:52 unbound: [44037:0] error: module init for module python failed Jan 22 22:08:52 unbound: [44037:0] error: pythonmod: can't open file pfb_unbound.py for reading Jan 22 22:08:51 unbound: [44037:0] notice: init module 0: python Jan 22 22:07:49 unbound: [82094:0] notice: init module 0: python Jan 22 22:07:49 unbound: [51734:0] info: 4.000000 8.000000 1 Jan 22 22:07:49 unbound: [51734:0] info: 2.000000 4.000000 2 Jan 22 22:07:49 unbound: [51734:0] info: 1.000000 2.000000 5 Jan 22 22:07:49 unbound: [51734:0] info: 0.524288 1.000000 8 Jan 22 22:07:49 unbound: [51734:0] info: 0.262144 0.524288 6 Jan 22 22:07:49 unbound: [51734:0] info: 0.131072 0.262144 9 Jan 22 22:07:49 unbound: [51734:0] info: 0.065536 0.131072 7 Jan 22 22:07:49 unbound: [51734:0] info: 0.032768 0.065536 6 Jan 22 22:07:49 unbound: [51734:0] info: 0.016384 0.032768 13 Jan 22 22:07:49 unbound: [51734:0] info: 0.008192 0.016384 3 Jan 22 22:07:49 unbound: [51734:0] info: 0.004096 0.008192 2 Jan 22 22:07:49 unbound: [51734:0] info: 0.000000 0.000001 1 Jan 22 22:07:49 unbound: [51734:0] info: lower(secs) upper(secs) recursions Jan 22 22:07:49 unbound: [51734:0] info: [25%]=0.028672 median[50%]=0.126391 [75%]=0.539154 Jan 22 22:07:49 unbound: [51734:0] info: histogram of recursion processing times Jan 22 22:07:49 unbound: [51734:0] info: average recursion processing time 0.434923 sec Jan 22 22:07:49 unbound: [51734:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 63 recursion replies sent, 0 replies dropped, 0 states jostled out Jan 22 22:07:49 unbound: [51734:0] info: server stats for thread 1: requestlist max 12 avg 1.77778 exceeded 0 jostled 0 Jan 22 22:07:49 unbound: [51734:0] info: server stats for thread 1: 113 queries, 50 answers from cache, 63 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 22:07:49 unbound: [51734:0] info: 0.524288 1.000000 1 Jan 22 22:07:49 unbound: [51734:0] info: 0.262144 0.524288 3 Jan 22 22:07:49 unbound: [51734:0] info: 0.065536 0.131072 1 Jan 22 22:07:49 unbound: [51734:0] info: 0.016384 0.032768 4 Jan 22 22:07:49 unbound: [51734:0] info: 0.008192 0.016384 5 Jan 22 22:07:49 unbound: [51734:0] info: 0.004096 0.008192 1 Jan 22 22:07:49 unbound: [51734:0] info: lower(secs) upper(secs) recursions Jan 22 22:07:49 unbound: [51734:0] info: [25%]=0.0126976 median[50%]=0.022528 [75%]=0.283989 Jan 22 22:07:49 unbound: [51734:0] info: histogram of recursion processing times Jan 22 22:07:49 unbound: [51734:0] info: average recursion processing time 0.128478 sec Jan 22 22:07:49 unbound: [51734:0] info: mesh has 0 recursion states (0 with reply, 0 detached), 0 waiting replies, 15 recursion replies sent, 0 replies dropped, 0 states jostled out Jan 22 22:07:49 unbound: [51734:0] info: server stats for thread 0: requestlist max 4 avg 0.933333 exceeded 0 jostled 0 Jan 22 22:07:49 unbound: [51734:0] info: server stats for thread 0: 34 queries, 19 answers from cache, 15 recursions, 0 prefetch, 0 rejected by ip ratelimiting Jan 22 22:07:49 unbound: [51734:0] info: service stopped (unbound 1.10.1).
Regards
Jürgen -
-
@cantor said in pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!:
Jan 22 22:08:52 unbound: [44037:0] fatal error: failed to setup modules
Jan 22 22:08:52 unbound: [44037:0] error: module init for module python failed
Jan 22 22:08:52 unbound: [44037:0] error: pythonmod: can't open file pfb_unbound.py for readingRe-install the package as this file is missing
-
I reinstalled pfBlockerNG and triggered Forced Reload-DNSBL. Everything seemed fine and DNS resolver was up with Unbound python mode.
Then I rebooted the box for a second check and unfortunately the resolver was down again with error "can't open file pfb_unbound.py for reading".
-
@cantor
You can't use RamDisks, since the /var/ folder is wiped on reboot. Need to disable that option, and reinstall once more to get the python script back. -
Ouch! That's it. Thanks for your help. Now everything works fine. :-)
-
I'm looking for a little clarification regarding the unbound config changes after switching to python mode.
- I've notice that unbound is unstarted after any pfBlockerNG-devel v3.x.x package updates. DNS lookups fail so I have to manually restart it.
- The docs indicate to change the interface to localhost in unbound. I assume it's the "Outgoing Network Interfaces" (now set to "localhost") and not the "Network Interfaces" (currently set to "all") above it.
- My DNS settings in general setup already has localhost configured (Disable DNS Forwarder is unchecked) as one of the upstream DNS servers. Do I keep this config or remove 127.0.0.1?
127.0.0.1
9.9.9.9
149.112.112.112
2620:fe::fe
2620:fe::9
So...have I made the correct changes? It seems to be working so far but want a 2nd opinion via another set of eyes to make sure I've understood the intended setup.
-
been bombarded by this dont know what happens but im blocking ipv6 everywhere.
[02-Mar-2021 15:29:50 Asia/Manila] PHP Fatal error: Uncaught Error: Class 'Net_IPv6' not found in /etc/inc/util.inc:680
Stack trace:
#0 /etc/inc/util.inc(657): is_ipaddrv6('pagead2.googles...')
#1 /usr/local/www/pfblockerng/www/index.php(59): is_ipaddr('pagead2.googles...')
#2 {main}
thrown in /etc/inc/util.inc on line 680 -
@thegenius21
See also here (not posted in the pfB section although probably a pfB related issue). -
I have tried to install the latest version of PFblockerNg v3.0 however the initialisation is still running after 30 mins. Unloaded older version and tryting to load latest version but still hangs. What is the CLI to install manually please?
-
There's no CLI command to install "pfSense"packages.
What happens when you install a 'simple/small' pfSense package like 'Cron' ?
-
@mikeelawson said in pfBlockerNG-devel v3.0.0 - No longer bound by Unbound!:
I have tried to install the latest version of PFblockerNg v3.0 however the initialisation is still running after 30 mins. Unloaded older version and tryting to load latest version but still hangs. What is the CLI to install manually please?
Related to this:
https://redmine.pfsense.org/issues/11398If you wait at the page it will eventually timeout. While it is in that condition, you can kill the Unbound pid and it should complete faster. Then restart Unbound post-install.
pkill unbound
-
@bbcan177 I have tried the unbound command, but again just hangs when I try to install.
-
@mikeelawson
At what point ?
Any logs ? Screenshot ? -
@gertjan It started happening when I tried to install new package. Screenshot, just shows initialising, no further update