DNS-Resolver macht Probleme seit Upgrade auf 24.03
-
Hallo Leute,
Letztes Wochenende hab ich meine pfSense (SG 2100) mal wieder auf Stand gebracht und mir damit leider wieder alte (bereits behobene) Probleme ins Haus geholt.
Im Zuge wurde auch auf den neuen Kea-DHCP umgestellt.Das Problem:
Es verhält sich ähnlich wie damals, als ich noch die relative kurze default DHCP-Leasetime eingestellt und zusätzlich die DNS-Registrierung von DHCP-Geräten aktiv hatte. Manchmal scheint der DNS nen kurzen Schluckauf zu haben. Wenn genau zu dem Zeitpunkt eins meiner Geräte ne Anfrage ohne brauchbare Antwort stellt, fängt's an zu spinnen. Ich muss dann immer den DNS-Cache am Endgerät leeren, damit dann genau diese fehl gelaufene Anfrage erneut gestellt wird und mir nicht der DNS-Cache reinspuckt. Äußerst anstrengend, weil's so nicht reproduziertbar passier.Es passiert dann, dass zB. einzelne Devices meinen Homeassistent nicht mehr auflösen wollen. Grade Android ist da echt ne Zicke. Geht dann oft erst nach nem Reboot wieder.
Oder beim Internet Surfen können willkürlich Websites nicht mehr aufgelöst werden.Anbei das Resolver Log: Ich seh eigentlich keine Restarts des Services. Nur täglich um kurz nach Mitternacht den Restart vom pfblockerNG (Cron Task).
Ach ja. Es gibt scheinbar die Menüpunkte zum Deaktivieren der DNS-Registrierungen durch den DHCP-Server gar nicht mehr. Ist das jetzt vermutlich eh per default abgedreht, oder?
Sep 2 10:13:38 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 10:13:38 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 09:27:22 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 08:30:08 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 07:39:51 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 07:34:02 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 06:48:31 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 06:48:31 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 06:20:08 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 06:20:08 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 05:50:51 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 05:23:06 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 04:31:09 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 03:48:41 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 02:51:46 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 02:51:45 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 02:23:34 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 01:50:07 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:51:13 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:51:13 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:30:09 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:19:49 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:19:49 unbound 84518 [84518:0] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:01:10 unbound 84518 [84518:1] info: generate keytag query _ta-4f66. NULL IN Sep 2 00:01:07 unbound 84518 [84518:0] info: start of service (unbound 1.19.3). Sep 2 00:01:07 unbound 84518 [84518:0] notice: init module 2: iterator Sep 2 00:01:07 unbound 84518 [84518:0] notice: init module 1: validator Sep 2 00:01:07 unbound 84518 [84518:0] info: [pfBlockerNG]: init_standard script loaded Sep 2 00:01:04 unbound 84518 [84518:0] info: [pfBlockerNG]: pfb_unbound.py script loaded Sep 2 00:01:03 unbound 84518 [84518:0] notice: init module 0: python Sep 2 00:01:02 unbound 31975 [31975:0] info: [pfBlockerNG]: pfb_unbound.py script exiting Sep 2 00:01:02 unbound 31975 [31975:0] info: 64.000000 128.000000 43 Sep 2 00:01:02 unbound 31975 [31975:0] info: 32.000000 64.000000 235 Sep 2 00:01:02 unbound 31975 [31975:0] info: 16.000000 32.000000 796 Sep 2 00:01:02 unbound 31975 [31975:0] info: 8.000000 16.000000 737 Sep 2 00:01:02 unbound 31975 [31975:0] info: 4.000000 8.000000 285 Sep 2 00:01:02 unbound 31975 [31975:0] info: 2.000000 4.000000 182 Sep 2 00:01:02 unbound 31975 [31975:0] info: 1.000000 2.000000 250 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.524288 1.000000 306 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.262144 0.524288 746 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.131072 0.262144 1959 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.065536 0.131072 3759 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.032768 0.065536 2803 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.016384 0.032768 1200 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.008192 0.016384 1526 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.004096 0.008192 19 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.002048 0.004096 12 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.001024 0.002048 8 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.000512 0.001024 3 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.000128 0.000256 2 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.000000 0.000001 1718 Sep 2 00:01:02 unbound 31975 [31975:0] info: lower(secs) upper(secs) recursions Sep 2 00:01:02 unbound 31975 [31975:0] info: [25%]=0.0281156 median[50%]=0.0830314 [75%]=0.224191 Sep 2 00:01:02 unbound 31975 [31975:0] info: histogram of recursion processing times Sep 2 00:01:02 unbound 31975 [31975:0] info: average recursion processing time 2.637729 sec Sep 2 00:01:02 unbound 31975 [31975:0] info: server stats for thread 1: requestlist max 39 avg 1.54637 exceeded 0 jostled 0 Sep 2 00:01:02 unbound 31975 [31975:0] info: server stats for thread 1: 549364 queries, 532775 answers from cache, 16589 recursions, 491 prefetch, 0 rejected by ip ratelimiting Sep 2 00:01:02 unbound 31975 [31975:0] info: 64.000000 128.000000 40 Sep 2 00:01:02 unbound 31975 [31975:0] info: 32.000000 64.000000 267 Sep 2 00:01:02 unbound 31975 [31975:0] info: 16.000000 32.000000 566 Sep 2 00:01:02 unbound 31975 [31975:0] info: 8.000000 16.000000 815 Sep 2 00:01:02 unbound 31975 [31975:0] info: 4.000000 8.000000 369 Sep 2 00:01:02 unbound 31975 [31975:0] info: 2.000000 4.000000 144 Sep 2 00:01:02 unbound 31975 [31975:0] info: 1.000000 2.000000 154 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.524288 1.000000 261 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.262144 0.524288 697 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.131072 0.262144 1815 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.065536 0.131072 3872 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.032768 0.065536 2678 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.016384 0.032768 1215 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.008192 0.016384 1571 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.004096 0.008192 10 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.002048 0.004096 5 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.001024 0.002048 5 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.000512 0.001024 1 Sep 2 00:01:02 unbound 31975 [31975:0] info: 0.000000 0.000001 1576 Sep 2 00:01:02 unbound 31975 [31975:0] info: lower(secs) upper(secs) recursions Sep 2 00:01:02 unbound 31975 [31975:0] info: [25%]=0.027809 median[50%]=0.0819454 [75%]=0.21143 Sep 2 00:01:02 unbound 31975 [31975:0] info: histogram of recursion processing times Sep 2 00:01:02 unbound 31975 [31975:0] info: average recursion processing time 2.511928 sec Sep 2 00:01:02 unbound 31975 [31975:0] info: server stats for thread 0: requestlist max 60 avg 1.63276 exceeded 0 jostled 0 Sep 2 00:01:02 unbound 31975 [31975:0] info: server stats for thread 0: 557417 queries, 541356 answers from cache, 16061 recursions, 454 prefetch, 0 rejected by ip ratelimiting Sep 2 00:01:01 unbound 31975 [31975:0] info: service stopped (unbound 1.19.3). Sep 1 23:19:48 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 22:35:01 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 22:30:33 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 22:08:28 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 21:13:15 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 20:30:08 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 20:30:08 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 20:10:15 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 19:40:05 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 19:19:47 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 19:19:47 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 18:23:05 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 18:02:05 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 17:25:55 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 16:31:55 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 15:35:01 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 15:31:45 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 15:04:56 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 14:05:32 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 13:30:04 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 12:43:11 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 12:35:47 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 11:40:07 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 10:50:07 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 10:17:09 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 09:33:04 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 09:28:27 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 09:28:27 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 09:10:15 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 08:30:07 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 07:49:02 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 07:17:22 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 06:50:07 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 06:18:47 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 05:23:30 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 04:40:15 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 04:40:15 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 04:35:01 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 03:50:07 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 03:18:47 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 02:34:59 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 02:18:32 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 02:18:32 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 02:02:05 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 01:51:17 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 01:32:06 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 01:10:15 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 01:10:15 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 00:19:49 unbound 31975 [31975:0] info: generate keytag query _ta-4f66. NULL IN Sep 1 00:01:17 unbound 31975 [31975:1] info: generate keytag query _ta-4f66. NULL IN Sep 1 00:01:17 unbound 31975 [31975:0] info: start of service (unbound 1.19.3). Sep 1 00:01:17 unbound 31975 [31975:0] notice: init module 2: iterator Sep 1 00:01:17 unbound 31975 [31975:0] notice: init module 1: validator Sep 1 00:01:17 unbound 31975 [31975:0] info: [pfBlockerNG]: init_standard script loaded Sep 1 00:01:13 unbound 31975 [31975:0] info: [pfBlockerNG]: pfb_unbound.py script loaded Sep 1 00:01:13 unbound 31975 [31975:0] notice: init module 0: python Sep 1 00:01:11 unbound 18204 [18204:0] info: [pfBlockerNG]: pfb_unbound.py script exiting Sep 1 00:01:11 unbound 18204 [18204:0] info: 128.000000 256.000000 1 Sep 1 00:01:11 unbound 18204 [18204:0] info: 64.000000 128.000000 2 Sep 1 00:01:11 unbound 18204 [18204:0] info: 32.000000 64.000000 114 Sep 1 00:01:11 unbound 18204 [18204:0] info: 16.000000 32.000000 119 Sep 1 00:01:11 unbound 18204 [18204:0] info: 8.000000 16.000000 107 Sep 1 00:01:11 unbound 18204 [18204:0] info: 4.000000 8.000000 49 Sep 1 00:01:11 unbound 18204 [18204:0] info: 2.000000 4.000000 25 Sep 1 00:01:11 unbound 18204 [18204:0] info: 1.000000 2.000000 16 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.524288 1.000000 54 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.262144 0.524288 103 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.131072 0.262144 304 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.065536 0.131072 587 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.032768 0.065536 420 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.016384 0.032768 150 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.008192 0.016384 256 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.004096 0.008192 1 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.002048 0.004096 2 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.000000 0.000001 254 Sep 1 00:01:11 unbound 18204 [18204:0] info: lower(secs) upper(secs) recursions Sep 1 00:01:11 unbound 18204 [18204:0] info: [25%]=0.030365 median[50%]=0.0877535 [75%]=0.240155 Sep 1 00:01:11 unbound 18204 [18204:0] info: histogram of recursion processing times Sep 1 00:01:11 unbound 18204 [18204:0] info: average recursion processing time 3.925973 sec Sep 1 00:01:11 unbound 18204 [18204:0] info: server stats for thread 1: requestlist max 33 avg 2.16794 exceeded 0 jostled 0 Sep 1 00:01:11 unbound 18204 [18204:0] info: server stats for thread 1: 77529 queries, 74965 answers from cache, 2564 recursions, 62 prefetch, 0 rejected by ip ratelimiting Sep 1 00:01:11 unbound 18204 [18204:0] info: 64.000000 128.000000 3 Sep 1 00:01:11 unbound 18204 [18204:0] info: 32.000000 64.000000 103 Sep 1 00:01:11 unbound 18204 [18204:0] info: 16.000000 32.000000 54 Sep 1 00:01:11 unbound 18204 [18204:0] info: 8.000000 16.000000 41 Sep 1 00:01:11 unbound 18204 [18204:0] info: 4.000000 8.000000 45 Sep 1 00:01:11 unbound 18204 [18204:0] info: 2.000000 4.000000 20 Sep 1 00:01:11 unbound 18204 [18204:0] info: 1.000000 2.000000 33 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.524288 1.000000 72 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.262144 0.524288 155 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.131072 0.262144 284 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.065536 0.131072 488 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.032768 0.065536 374 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.016384 0.032768 177 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.008192 0.016384 248 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.004096 0.008192 3 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.002048 0.004096 1 Sep 1 00:01:11 unbound 18204 [18204:0] info: 0.000000 0.000001 231 Sep 1 00:01:11 unbound 18204 [18204:0] info: lower(secs) upper(secs) recursions Sep 1 00:01:11 unbound 18204 [18204:0] info: [25%]=0.0256405 median[50%]=0.083263 [75%]=0.235837 Sep 1 00:01:11 unbound 18204 [18204:0] info: histogram of recursion processing times Sep 1 00:01:11 unbound 18204 [18204:0] info: average recursion processing time 3.032051 sec Sep 1 00:01:11 unbound 18204 [18204:0] info: server stats for thread 0: requestlist max 23 avg 1.45106 exceeded 0 jostled 0 Sep 1 00:01:11 unbound 18204 [18204:0] info: server stats for thread 0: 74090 queries, 71758 answers from cache, 2332 recursions, 69 prefetch, 0 rejected by ip ratelimiting Sep 1 00:01:11 unbound 18204 [18204:0] info: service stopped (unbound 1.19.3).
-
@n300 keine Ahnung, ob es im Zusammenhang steht, ich hätte noch gewartet mit der Umstellung auf den KEA-DHCP (wenn du den Aktuellen Newsletter von Netgate gelesen hast, haben sie ja auch schon neue infos zum KEA Stand)
-
@micneu
OK, guter Punkt. Ich hab mal wieder auf den alten DHCP zurückgestellt und werde weiter beobachten :) -
@n300 KEA in jedem Release VOR plus-24.08 ist ALPHA und sollte entsprechend NUR dann benutzt werden, wenn man aktiv die entsprechenden Doks, Changelogs etc. gelesen hat. Das sind alles Probleme die direkt auf der ersten Seite Changelog/Release Notes von Key stehen und jetzt u.a. im Blog zu 24.08 adressiert werden, dass dort die Entwicklung sich langsam "feature parity" mit ISC DHCPd nähert. Bevor DAS nirgends steht, gibts überhaupt keinen Grund was zu ändern.
Cheers :)
-
@JeGr
Genau, daher hab ich's jetzt auch wieder zurückgestellt. Finde es nur etwas unglücklich in der UI, dass hier seit 2 Releases so prominent auf den deprecated Status hingewiesen wird. Wenn man auf das vertraut und nicht extra recherchieren geht, könnte man meinen, der ISC ist mit dem nächsten Release gar nicht mehr vorhanden. -
@n300 Da bin ich bei dir, den Alarmismus-Grad der Meldung fand ich auch etwas zu stark gemessen an "Umstellen sollte man erst wenn das Ding wesentlich mehr Features hat" (also je nach Einsatzzweck mit der kommenden 24.08) - das erweckt leider mitunter die Idee, man müsste hier akuter tätig werden, als es ist.