Project

General

Profile

Actions
Copy link

Bug #11553

closed

Unbound does not restart properly sometimes when DHCP Registration is enabled

Added by Kris Phillips over 3 years ago. Updated over 3 years ago.

Status:
Duplicate
Priority:
Normal
Assignee:
-
Category:
DNS Resolver
Target version:
-
Start date:
02/26/2021
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Release Notes:
Affected Version:
All
Affected Architecture:
All

Description

Running the latest unbound (1.13.1) with the DHCP Registration setting enabled where DHCP entries get inserted in the DNS server's hostnames restarts the unbound service with new registrations. However, it does not reliably start the service back up again. This is unrelated to the segfault bug that existed with 1.13.0_2 but seems to be a new form of unreliability, as there is no segfault but the service fails to start back up anyway.

DHCP logs:
Feb 25 12:42:29 pfsense dhcpleases55541: Sending HUP signal to dns daemon(12799)
Feb 25 12:42:29 pfsense dhcpleases55541: Could not deliver signal HUP to process 12799: No such process.

DNS Logs (Restart is user intervention):
Feb 25 12:42:25 pfsense unbound12799: [12799:0] info: service stopped (unbound 1.13.1).
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 0: 177 queries, 86 answers from cache, 91 recursions, 1 prefetch, 0 rejected by ip ratelimiting
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 0: requestlist max 2 avg 0.119565 exceeded 0 jostled 0
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: average recursion processing time 0.215772 sec
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: histogram of recursion processing times
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: [25%]=0.0928427 median[50%]=0.194788 [75%]=0.310584
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: lower(secs) upper(secs) recursions
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.000000 0.000001 7
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.032768 0.065536 12
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.065536 0.131072 9
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.131072 0.262144 36
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.262144 0.524288 23
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.524288 1.000000 3
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 1.000000 2.000000 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 1: 2461 queries, 1512 answers from cache, 949 recursions, 15 prefetch, 0 rejected by ip ratelimiting
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 1: requestlist max 29 avg 1.70124 exceeded 0 jostled 0
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: average recursion processing time 0.190440 sec
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: histogram of recursion processing times
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: [25%]=0.0522377 median[50%]=0.118101 [75%]=0.24367
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: lower(secs) upper(secs) recursions
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.000000 0.000001 50
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.001024 0.002048 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.004096 0.008192 4
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.016384 0.032768 4
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.032768 0.065536 300
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.065536 0.131072 144
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.131072 0.262144 243
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.262144 0.524288 140
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.524288 1.000000 55
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 1.000000 2.000000 7
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 2.000000 4.000000 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 2: 1125 queries, 608 answers from cache, 517 recursions, 7 prefetch, 0 rejected by ip ratelimiting
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 2: requestlist max 35 avg 4.06489 exceeded 0 jostled 0
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: average recursion processing time 0.268351 sec
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: histogram of recursion processing times
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: [25%]=0.0637751 median[50%]=0.196608 [75%]=0.374023
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: lower(secs) upper(secs) recursions
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.000000 0.000001 28
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.032768 0.065536 107
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.065536 0.131072 54
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.131072 0.262144 139
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.262144 0.524288 140
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.524288 1.000000 43
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 1.000000 2.000000 4
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 2.000000 4.000000 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 4.000000 8.000000 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 3: 3495 queries, 2211 answers from cache, 1284 recursions, 20 prefetch, 0 rejected by ip ratelimiting
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: server stats for thread 3: requestlist max 42 avg 1.43712 exceeded 0 jostled 0
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: average recursion processing time 0.158562 sec
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: histogram of recursion processing times
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: [25%]=0.0477867 median[50%]=0.0862611 [75%]=0.20118
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: lower(secs) upper(secs) recursions
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.000000 0.000001 103
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.001024 0.002048 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.004096 0.008192 3
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.008192 0.016384 2
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.016384 0.032768 3
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.032768 0.065536 456
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.065536 0.131072 234
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.131072 0.262144 301
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.262144 0.524288 98
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 0.524288 1.000000 76
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 1.000000 2.000000 5
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 2.000000 4.000000 1
Feb 25 12:42:27 pfsense unbound12799: [12799:0] info: 4.000000 8.000000 1
Feb 25 12:43:26 pfsense unbound61614: [61614:0] notice: init module 0: validator
Feb 25 12:43:26 pfsense unbound61614: [61614:0] notice: init module 1: iterator
Feb 25 12:43:26 pfsense unbound61614: [61614:0] info: start of service (unbound 1.13.1).

Related issues

Related to Bug #5413: Reduce disruptions when changing DNS records from DHCP leases in UnboundResolvedChristian McDonald11/10/2015

Actions
Actions
Copy link
 #1

Updated by Jim Pingle over 3 years ago

  • Project changed from pfSense Plus to pfSense
  • Category changed from DNS Resolver to DNS Resolver
  • Status changed from New to Duplicate
  • Affected Plus Version deleted (21.02)
  • Affected Version set to All

Not specific to Plus.

The core of this is already covered by #5413 -- there may be some other Unbound bug beyond that, but solving #5413 would most likely also solve this.

Actions
Copy link
 #2

Updated by Jim Pingle over 3 years ago

  • Related to Bug #5413: Reduce disruptions when changing DNS records from DHCP leases in Unbound added
Actions
Copy link
 #3

Updated by Marcos M over 3 years ago

Some additional info:

To work around the issue in this case this was reported from, one can do either of the following:
  1. Disable DHCP name resolving
  2. Delete pfblocker lists (only disabling pfblocker does not work, as the lists are still built in unbound - but if you delete the large lists, it will allow DHCP name resolving)
Actions
Copy link

Also available in: Atom PDF