Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    PfBlockerNG - Stop Unbound.

    Scheduled Pinned Locked Moved pfBlockerNG
    4 Posts 2 Posters 2.0k Views 2 Watching
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • A Offline
      akkuladezeit
      last edited by akkuladezeit

      I got a strange behavior on Pfsense+ with pfBlockerNG

      Pfsense Version: 25.0.7.1
      pfBlockerNG Version: 3.2.8
      Kea DHCP

      Every 4h the cron-jop is running for updating ip/dnsbl

      after some Days DNS resolving didnt work anymore.
      I started investigation ;)

      in the systemlog/system/general if found many of this entries:

      kernel   sonewconn: pcb 0xfffff803cd9fb540 (192.168.5.1:53 (proto 6)): Listen queue overflow: 193 already in queue awaiting acceptance (267 occurrences), euid 0, rgid 0, jail 0
kernel   sonewconn: pcb 0xfffff803cd9fb540 (192.168.5.1:53 (proto 6)): Listen queue overflow: 193 already in queue awaiting acceptance (179 occurrences), euid 0, rgid 0, jail 0
...

      -> So it seams that the unbound do not perform resolving and the queue gets an overflow.
      in the webinterface the unbound-task is running - but restarting didnt worked.
      -> so i checked via ssh:

      [25.07.1-RELEASE][admin@pfSense.arpa]/root: ps aux | grep unbound
unbound 49667   69.6  7.0 1345852 1153996  -  Ts   04:00     102:48.82 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
root     7713    0.0  0.0   14420    3152  -  I    10:22       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound  7965    0.0  0.1   28880   15980  -  I    10:22       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root     8356    0.0  0.0   14420    3148  -  I    09:36       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound  9114    0.0  0.1   28880   15980  -  I    09:36       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    26810    0.0  0.0   14420    3144  -  I    09:41       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 27081    0.0  0.1   28880   15976  -  I    09:41       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    28811    0.0  0.0   14420    3144  -  I    09:29       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 29012    0.0  0.1   28880   15988  -  I    09:29       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    29771    0.0  0.0   14644    3096  -  I    08:00       0:00.00 /bin/sh /conf/kea4_scripts.d/kea2unbound.sh lease4_update
root    30004    0.0  0.2   63352   39392  -  I    08:00       0:00.02 php /usr/local/bin/kea2unbound --kea-conf /usr/local/etc/kea/kea-dhcp4.conf --unbound-conf /var/unbound/unbound.conf --include-file /var/unbound/leases/leases4.conf sync
root    35986    0.0  0.1   28880   15972  -  I    08:00       0:00.00 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf list_local_data
root    80811    0.0  0.0   14420    3156  -  I    10:24       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 81084    0.0  0.1   28880   15976  -  I    10:24       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    98355    0.0  0.0   14420    3148  -  I    09:37       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 98549    0.0  0.1   28880   15976  -  I    09:37       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    24580    0.0  0.0   14420    3140  0  I    10:17       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 24768    0.0  0.0   14644    3340  0  I    10:17       0:00.00 /bin/sh /etc/rc.initial -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 24889    0.0  0.1   28880   15972  0  I    10:17       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
root    72975    0.0  0.0   14076    2688  0  S+   10:31       0:00.00 grep unbound
root    78483    0.0  0.0   14420    3148  0  I    09:49       0:00.00 /usr/bin/su -m unbound -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 78582    0.0  0.0   14644    3352  0  I    09:49       0:00.00 /bin/sh /etc/rc.initial -c /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload
unbound 78598    0.0  0.1   28880   15980  0  I    09:49       0:00.01 /usr/local/sbin/unbound-control -c /var/unbound/unbound.conf reload

      in my opinion too much unbound related stuff is open and too high load on pid 49667.
      -> so i tried killing the process via "kill -9" but it can't stop the process.

      So checked the sockstat...

      [25.07.1-RELEASE][admin@pfSense.arpa]/root: sockstat -4 -l
USER     COMMAND    PID   FD  PROTO  LOCAL ADDRESS         FOREIGN ADDRESS      
...
root     nginx      50655 5   tcp4   *:443                 *:*
root     nginx      50655 7   tcp4   *:80                  *:*
?        ?          ?     ?   tcp4   192.168.5.1:853       *:*
?        ?          ?     ?   udp4   192.168.5.1:53        *:*
?        ?          ?     ?   tcp4   192.168.5.1:53        *:*
...

      seams the port are open but no process ... seams we got an unbound zombie.

      after some search in the logs i found that for every cron jop the unbound gets stopped and restarted after a few seconds.
      but not in some of my cases (cron jop). It only got stop but nerver restarted.

      After i perfom a manually pfblocker-Update "Reload" the unbound starts working again. And i got an expected ps..

      [25.07.1-RELEASE][admin@pfSense.arpa]/root: ps aux | grep unbound
unbound 29882    0.0  7.3 1373880 1195556  -  Ss   10:35       0:07.87 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
root    38805    0.0  0.1   21396    9996  -  S    10:35       0:00.26 /usr/local/sbin/lighttpd_pfb -f /var/unbound/pfb_dnsbl_lighty.conf
root    25276    0.0  0.0   14076    2680  0  S+   10:48       0:00.01 grep unbound

      after a few weeks i tried the service watchdog, but it dont restarts the unbound because the zombie process...

      Has anyone an idea what the problem could be?

      BBcan177B 1 Reply Last reply Reply Quote 0
      • BBcan177B Offline
        BBcan177 Moderator @akkuladezeit
        last edited by

        @akkuladezeit if you are not using Python mode, please switch to that with KEA.

        "Experience is something you don't get until just after you need it."

        Website: http://pfBlockerNG.com
        Twitter: @BBcan177  #pfBlockerNG
        Reddit: https://www.reddit.com/r/pfBlockerNG/new/

        A 1 Reply Last reply Reply Quote 0
        • A Offline
          akkuladezeit @BBcan177
          last edited by

          @BBcan177 thank for replay.

          Im already in Python Mode. Maybe its an issue in combination with Kea.

          This Night it Happen again but not at DNSBL Cron Job time…
          Unbound was stoppen at 3:13 am.

          I will post the Logs When im at the PC

          A 1 Reply Last reply Reply Quote 0
          • A Offline
            akkuladezeit @akkuladezeit
            last edited by akkuladezeit

            Based on the Timings it seams that KEA stuff stopped the Unbound and don't start it again?
            or just coincidence?
            i currently not understand by kea is involved, because i didn't have activated dhcp lease to dns ... (DNS Registration)

            But its also strange the unbound gets two time restarted on pfblockerng cron-task

            General Log:

            Sep 28 00:00:00 	php 	12862 	[pfBlockerNG] Starting cron process.
Sep 28 00:00:31 	php 	12862 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 01:00:00 	php 	71023 	[pfBlockerNG] Starting cron process.
Sep 28 01:00:14 	php 	71023 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 02:00:00 	php 	5372 	[pfBlockerNG] Starting cron process.
Sep 28 02:00:22 	php 	5372 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 03:00:00 	php 	37595 	[pfBlockerNG] Starting cron process.
Sep 28 03:00:31 	php 	37595 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 03:01:00 	root 	31193 	rc.update_bogons.sh is starting up.
Sep 28 03:01:00 	root 	32722 	rc.update_bogons.sh is sleeping for 66003 
Sep 28 04:00:00 	php 	49188 	[pfBlockerNG] Starting cron process.
Sep 28 04:20:17 	php 	49188 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 05:00:00 	php 	29707 	[pfBlockerNG] Starting cron process.
Sep 28 05:05:16 	php 	29707 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload
Sep 28 06:00:00 	php 	3228 	[pfBlockerNG] Starting cron process.
Sep 28 06:00:00 	php-cgi 	4046 	[Suricata] Checking for updated MaxMind GeoLite2 IP database file...
Sep 28 06:01:00 	php-cgi 	4046 	[Suricata] ERROR: GeoLite2-Country IP database download failed. The HTTP Response Code was .
Sep 28 06:01:00 	php-cgi 	4046 	[Suricata] ERROR: GeoLite2-Country IP database update check failed. The GeoIP database was not updated!
Sep 28 06:01:00 	php-cgi 	4046 	[Suricata] Cleaning up temp files after GeoLite2-Country database update.
Sep 28 06:05:16 	php 	3228 	[pfBlockerNG] No changes to Firewall rules, skipping Filter Reload

            DNS-Resolver Log:

            Sep 28 00:00:23 	unbound 	27650 	[27650:0] info: service stopped (unbound 1.23.0).
Sep 28 00:00:23 	unbound 	27650 	[27650:0] info: [pfBlockerNG]: pfb_unbound.py script exiting
Sep 28 00:00:24 	unbound 	29770 	[29770:0] notice: init module 0: python
Sep 28 00:00:24 	unbound 	29770 	[29770:0] info: [pfBlockerNG]: pfb_unbound.py script loaded
Sep 28 00:00:24 	unbound 	29770 	[29770:0] info: [pfBlockerNG]: init_standard script loaded
Sep 28 00:00:24 	unbound 	29770 	[29770:0] notice: init module 1: validator
Sep 28 00:00:24 	unbound 	29770 	[29770:0] notice: init module 2: iterator
Sep 28 00:00:24 	unbound 	29770 	[29770:0] info: start of service (unbound 1.23.0).
Sep 28 00:05:46 	unbound 	29770 	[29770:0] info: service stopped (unbound 1.23.0).
Sep 28 00:05:46 	unbound 	29770 	[29770:0] notice: Restart of unbound 1.23.0.
Sep 28 00:05:46 	unbound 	29770 	[29770:0] info: [pfBlockerNG]: pfb_unbound.py script exiting
Sep 28 00:05:46 	unbound 	29770 	[29770:0] notice: init module 0: python
Sep 28 00:05:46 	unbound 	29770 	[29770:0] info: [pfBlockerNG]: pfb_unbound.py script loaded
Sep 28 00:05:47 	unbound 	29770 	[29770:0] info: [pfBlockerNG]: init_standard script loaded
Sep 28 00:05:47 	unbound 	29770 	[29770:0] notice: init module 1: validator
Sep 28 00:05:47 	unbound 	29770 	[29770:0] notice: init module 2: iterator
Sep 28 00:05:47 	unbound 	29770 	[29770:0] info: start of service (unbound 1.23.0).
Sep 28 03:13:53 	unbound 	29770 	[29770:0] info: service stopped (unbound 1.23.0).

            DHCP Log:

            Sep 28 03:13:53 	kea2unbound 	88766 	Unbound reloaded: /var/unbound/unbound.conf
Sep 28 03:13:53 	kea2unbound 	88766 	Include updated: /var/unbound/leases/leases4.conf (a7cfad6c13eb8df1)
Sep 28 03:13:53 	kea2unbound 	88766 	Unbound lease include is missing or inconsistent: /var/unbound/leases/leases4.conf
Sep 28 00:05:46 	kea2unbound 	11822 	Unbound reloaded: /var/unbound/unbound.conf
Sep 28 00:05:46 	kea2unbound 	11822 	Include updated: /var/unbound/leases/leases4.conf (a7cfad6c13eb8df1)
Sep 28 00:05:46 	kea2unbound 	11822 	Unbound lease include is missing or inconsistent: /var/unbound/leases/leases4.conf
            1 Reply Last reply Reply Quote 0
            • First post
              Last post
            Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.